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/01 05:53:51 UTC
[JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.7.0_51) - Build #
9315 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9315/
Java: 64bit/jdk1.7.0_51 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.ShardSplitTest.testDistribSearch
Error Message:
Wrong doc count on shard1_0 expected:<327> but was:<307>
Stack Trace:
java.lang.AssertionError: Wrong doc count on shard1_0 expected:<327> but was:<307>
at __randomizedtesting.SeedInfo.seed([CCBD1350406F6D87:4D5B9D4837300DBB]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:477)
at org.apache.solr.cloud.ShardSplitTest.splitByUniqueKeyTest(ShardSplitTest.java:249)
at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:113)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:867)
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 10272 lines...]
[junit4] Suite: org.apache.solr.cloud.ShardSplitTest
[junit4] 2> 320287 T2329 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_/if
[junit4] 2> 320293 T2329 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1391229263411
[junit4] 2> 320293 T2329 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 320294 T2330 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 320394 T2329 oasc.ZkTestServer.run start zk server on port:59659
[junit4] 2> 320395 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 320811 T2336 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ae3ff85 name:ZooKeeperConnection Watcher:127.0.0.1:59659 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 320811 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 320811 T2329 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 320816 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 320817 T2338 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@52e7b886 name:ZooKeeperConnection Watcher:127.0.0.1:59659/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 320817 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 320817 T2329 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 320823 T2329 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 320826 T2329 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 320828 T2329 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 320830 T2329 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 320831 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 320837 T2329 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 320838 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 320840 T2329 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 320841 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 320843 T2329 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 320843 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 320845 T2329 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 320845 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 320847 T2329 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 320847 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 320849 T2329 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 320850 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 320852 T2329 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 320852 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 320854 T2329 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 320855 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 320856 T2329 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 320857 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 320859 T2329 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 320860 T2329 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 320935 T2329 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 320939 T2329 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:34377
[junit4] 2> 320939 T2329 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 320940 T2329 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 320940 T2329 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-controljetty-1391229263982
[junit4] 2> 320940 T2329 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-controljetty-1391229263982/'
[junit4] 2> 320954 T2329 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1391229263982/solr.xml
[junit4] 2> 321008 T2329 oasc.CoreContainer.<init> New CoreContainer 1378207586
[junit4] 2> 321008 T2329 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-controljetty-1391229263982/]
[junit4] 2> 321010 T2329 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 321010 T2329 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 321010 T2329 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 321011 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 321011 T2329 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 321011 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 321012 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 321012 T2329 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 321012 T2329 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 321016 T2329 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 321016 T2329 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 321016 T2329 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 321017 T2329 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59659/solr
[junit4] 2> 321017 T2329 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 321018 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 321023 T2349 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e451d10 name:ZooKeeperConnection Watcher:127.0.0.1:59659 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 321023 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 321025 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 321027 T2351 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5551a0a9 name:ZooKeeperConnection Watcher:127.0.0.1:59659/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 321027 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 321028 T2329 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 321035 T2329 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 321038 T2329 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 321041 T2329 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34377__%2Fif
[junit4] 2> 321045 T2329 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:34377__%2Fif
[junit4] 2> 321047 T2329 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 321049 T2329 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 321062 T2329 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:34377__%2Fif
[junit4] 2> 321062 T2329 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 321067 T2329 oasc.Overseer.start Overseer (id=91175601007034371-127.0.0.1:34377__%2Fif-n_0000000000) starting
[junit4] 2> 321071 T2329 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 321076 T2329 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 321078 T2329 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 321079 T2353 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 321079 T2329 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 321079 T2353 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 321082 T2352 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 321089 T2354 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 321089 T2354 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 321092 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 321092 T2354 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 321093 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 321094 T2352 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:34377/_/if",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:34377__%2Fif",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 321094 T2352 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 321094 T2352 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 321096 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 321097 T2351 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> 322094 T2354 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 322094 T2354 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-controljetty-1391229263982/collection1
[junit4] 2> 322094 T2354 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 322095 T2354 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 322095 T2354 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 322096 T2354 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-controljetty-1391229263982/collection1/'
[junit4] 2> 322096 T2354 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1391229263982/collection1/lib/classes/' to classloader
[junit4] 2> 322096 T2354 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1391229263982/collection1/lib/README' to classloader
[junit4] 2> 322125 T2354 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 322162 T2354 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 322163 T2354 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 322169 T2354 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 322452 T2354 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 322454 T2354 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 322455 T2354 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 322458 T2354 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 322477 T2354 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 322477 T2354 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-controljetty-1391229263982/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1391229263411/control/data/
[junit4] 2> 322478 T2354 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2fa45d6
[junit4] 2> 322478 T2354 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1391229263411/control/data
[junit4] 2> 322478 T2354 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1391229263411/control/data/index/
[junit4] 2> 322478 T2354 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1391229263411/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 322479 T2354 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1391229263411/control/data/index
[junit4] 2> 322479 T2354 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=56.3173828125, floorSegmentMB=1.908203125, forceMergeDeletesPctAllowed=23.41566170836658, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7525649374076314
[junit4] 2> 322480 T2354 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@472f359e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@58c628c3),segFN=segments_1,generation=1}
[junit4] 2> 322480 T2354 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 322482 T2354 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 322483 T2354 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 322483 T2354 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 322483 T2354 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 322483 T2354 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 322483 T2354 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 322484 T2354 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 322484 T2354 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 322484 T2354 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 322484 T2354 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 322485 T2354 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 322485 T2354 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 322485 T2354 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 322486 T2354 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 322486 T2354 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 322486 T2354 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 322487 T2354 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 322489 T2354 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 322491 T2354 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 322491 T2354 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 322492 T2354 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=48, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=59.2548828125, floorSegmentMB=1.7978515625, forceMergeDeletesPctAllowed=14.821505797190378, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 322492 T2354 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@472f359e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@58c628c3),segFN=segments_1,generation=1}
[junit4] 2> 322492 T2354 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 322492 T2354 oass.SolrIndexSearcher.<init> Opening Searcher@5cbe0c38 main
[junit4] 2> 322494 T2355 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5cbe0c38 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 322495 T2354 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 322496 T2329 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 322496 T2329 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 322496 T2358 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:34377/_/if collection:control_collection shard:shard1
[junit4] 2> 322497 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 322497 T2358 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 322499 T2360 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@614330b7 name:ZooKeeperConnection Watcher:127.0.0.1:59659/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 322499 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 322500 T2329 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 322502 T2329 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 322503 T2358 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 322504 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 322505 T2358 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 322505 T2358 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C387 name=collection1 org.apache.solr.core.SolrCore@6e9880ff url=http://127.0.0.1:34377/_/if/collection1 node=127.0.0.1:34377__%2Fif C387_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:34377/_/if, core=collection1, node_name=127.0.0.1:34377__%2Fif}
[junit4] 2> 322505 T2358 C387 P34377 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:34377/_/if/collection1/
[junit4] 2> 322505 T2358 C387 P34377 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 322505 T2358 C387 P34377 oasc.SyncStrategy.syncToMe http://127.0.0.1:34377/_/if/collection1/ has no replicas
[junit4] 2> 322506 T2358 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:34377/_/if/collection1/ shard1
[junit4] 2> 322506 T2358 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 322507 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 322514 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 322516 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 322578 T2329 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 322579 T2329 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 322581 T2329 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47037
[junit4] 2> 322581 T2329 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 322581 T2329 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 322581 T2329 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-jetty1-1391229265620
[junit4] 2> 322582 T2329 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty1-1391229265620/'
[junit4] 2> 322592 T2329 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1391229265620/solr.xml
[junit4] 2> 322619 T2360 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> 322619 T2351 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> 322627 T2329 oasc.CoreContainer.<init> New CoreContainer 1826779692
[junit4] 2> 322627 T2329 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-jetty1-1391229265620/]
[junit4] 2> 322628 T2329 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 322628 T2329 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 322628 T2329 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 322629 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 322629 T2329 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 322629 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 322629 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 322629 T2329 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 322629 T2329 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 322631 T2329 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 322632 T2329 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 322632 T2329 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 322632 T2329 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59659/solr
[junit4] 2> 322632 T2329 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 322633 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 322635 T2371 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b5de8d name:ZooKeeperConnection Watcher:127.0.0.1:59659 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 322635 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 322637 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 322639 T2373 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3f4f853 name:ZooKeeperConnection Watcher:127.0.0.1:59659/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 322639 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 322642 T2329 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 322665 T2358 oasc.ZkController.register We are http://127.0.0.1:34377/_/if/collection1/ and leader is http://127.0.0.1:34377/_/if/collection1/
[junit4] 2> 322665 T2358 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:34377/_/if
[junit4] 2> 322665 T2358 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 322666 T2358 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 322666 T2358 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 322667 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 322667 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 322667 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 322667 T2358 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 322669 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 322669 T2352 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:34377/_/if",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:34377__%2Fif",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 322672 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 322774 T2373 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> 322774 T2360 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> 322774 T2351 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> 323647 T2329 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47037__%2Fif
[junit4] 2> 323649 T2329 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47037__%2Fif
[junit4] 2> 323651 T2351 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 323651 T2360 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 323651 T2373 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 323657 T2374 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 323657 T2374 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 323658 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 323658 T2374 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 323658 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 323658 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 323659 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 323660 T2352 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:47037/_/if",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:47037__%2Fif",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 323660 T2352 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 323660 T2352 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 323662 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 323763 T2373 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> 323764 T2351 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> 323763 T2360 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> 324658 T2374 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 324658 T2374 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-jetty1-1391229265620/collection1
[junit4] 2> 324659 T2374 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 324659 T2374 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 324659 T2374 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 324660 T2374 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty1-1391229265620/collection1/'
[junit4] 2> 324661 T2374 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1391229265620/collection1/lib/classes/' to classloader
[junit4] 2> 324661 T2374 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1391229265620/collection1/lib/README' to classloader
[junit4] 2> 324691 T2374 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 324730 T2374 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 324731 T2374 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 324736 T2374 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 325027 T2374 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 325030 T2374 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 325032 T2374 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 325036 T2374 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 325053 T2374 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 325054 T2374 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-jetty1-1391229265620/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty1/
[junit4] 2> 325054 T2374 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2fa45d6
[junit4] 2> 325054 T2374 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty1
[junit4] 2> 325054 T2374 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty1/index/
[junit4] 2> 325054 T2374 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 325055 T2374 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty1/index
[junit4] 2> 325055 T2374 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=56.3173828125, floorSegmentMB=1.908203125, forceMergeDeletesPctAllowed=23.41566170836658, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7525649374076314
[junit4] 2> 325056 T2374 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7f3c1231 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@774ef8e0),segFN=segments_1,generation=1}
[junit4] 2> 325056 T2374 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 325059 T2374 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 325059 T2374 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 325059 T2374 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 325059 T2374 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 325059 T2374 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 325060 T2374 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 325060 T2374 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 325060 T2374 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 325060 T2374 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 325061 T2374 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 325061 T2374 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 325061 T2374 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 325061 T2374 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 325062 T2374 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 325062 T2374 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 325062 T2374 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 325063 T2374 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 325065 T2374 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 325068 T2374 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 325068 T2374 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 325069 T2374 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=48, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=59.2548828125, floorSegmentMB=1.7978515625, forceMergeDeletesPctAllowed=14.821505797190378, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 325069 T2374 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7f3c1231 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@774ef8e0),segFN=segments_1,generation=1}
[junit4] 2> 325069 T2374 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 325070 T2374 oass.SolrIndexSearcher.<init> Opening Searcher@3f1b1903 main
[junit4] 2> 325072 T2375 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3f1b1903 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 325075 T2374 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 325076 T2329 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 325076 T2329 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 325076 T2378 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:47037/_/if collection:collection1 shard:shard1
[junit4] 2> 325077 T2378 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 325082 T2378 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 325084 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 325084 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 325084 T2378 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 325084 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 325084 T2378 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C388 name=collection1 org.apache.solr.core.SolrCore@55fb7ae2 url=http://127.0.0.1:47037/_/if/collection1 node=127.0.0.1:47037__%2Fif C388_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:47037/_/if, core=collection1, node_name=127.0.0.1:47037__%2Fif}
[junit4] 2> 325084 T2378 C388 P47037 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:47037/_/if/collection1/
[junit4] 2> 325085 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 325085 T2378 C388 P47037 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 325085 T2378 C388 P47037 oasc.SyncStrategy.syncToMe http://127.0.0.1:47037/_/if/collection1/ has no replicas
[junit4] 2> 325085 T2378 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:47037/_/if/collection1/ shard1
[junit4] 2> 325085 T2378 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 325088 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 325091 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 325094 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 325152 T2329 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 325152 T2329 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 325155 T2329 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52812
[junit4] 2> 325156 T2329 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 325156 T2329 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 325156 T2329 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1391229268195
[junit4] 2> 325157 T2329 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1391229268195/'
[junit4] 2> 325177 T2329 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1391229268195/solr.xml
[junit4] 2> 325197 T2351 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> 325197 T2373 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> 325197 T2360 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> 325211 T2329 oasc.CoreContainer.<init> New CoreContainer 168071989
[junit4] 2> 325211 T2329 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1391229268195/]
[junit4] 2> 325212 T2329 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 325212 T2329 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 325212 T2329 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 325213 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 325213 T2329 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 325213 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 325213 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 325213 T2329 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 325213 T2329 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 325215 T2329 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 325216 T2329 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 325216 T2329 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 325216 T2329 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59659/solr
[junit4] 2> 325216 T2329 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 325217 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 325219 T2389 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@325c81b6 name:ZooKeeperConnection Watcher:127.0.0.1:59659 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 325219 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 325220 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 325221 T2391 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6565d29 name:ZooKeeperConnection Watcher:127.0.0.1:59659/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 325221 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 325224 T2329 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 325241 T2378 oasc.ZkController.register We are http://127.0.0.1:47037/_/if/collection1/ and leader is http://127.0.0.1:47037/_/if/collection1/
[junit4] 2> 325241 T2378 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:47037/_/if
[junit4] 2> 325242 T2378 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 325242 T2378 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 325242 T2378 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 325243 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 325243 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 325243 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 325243 T2378 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 325244 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 325244 T2352 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:47037/_/if",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:47037__%2Fif",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 325246 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 325348 T2351 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> 325348 T2391 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> 325348 T2360 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> 325348 T2373 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> 326226 T2329 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52812__%2Fif
[junit4] 2> 326228 T2329 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52812__%2Fif
[junit4] 2> 326232 T2360 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 326232 T2391 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 326232 T2351 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 326232 T2373 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 326243 T2392 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 326243 T2392 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 326245 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 326245 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 326246 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 326246 T2392 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 326248 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 326249 T2352 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:52812/_/if",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52812__%2Fif",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 326250 T2352 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 326250 T2352 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 326253 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 326356 T2351 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> 326356 T2373 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> 326356 T2360 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> 326356 T2391 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> 327247 T2392 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 327247 T2392 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1391229268195/collection1
[junit4] 2> 327247 T2392 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 327248 T2392 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 327248 T2392 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 327250 T2392 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1391229268195/collection1/'
[junit4] 2> 327251 T2392 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1391229268195/collection1/lib/classes/' to classloader
[junit4] 2> 327251 T2392 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1391229268195/collection1/lib/README' to classloader
[junit4] 2> 327297 T2392 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 327330 T2392 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 327332 T2392 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 327337 T2392 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 327618 T2392 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 327620 T2392 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 327622 T2392 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 327625 T2392 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 327650 T2392 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 327651 T2392 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1391229268195/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty2/
[junit4] 2> 327651 T2392 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2fa45d6
[junit4] 2> 327652 T2392 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty2
[junit4] 2> 327652 T2392 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty2/index/
[junit4] 2> 327653 T2392 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 327653 T2392 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty2/index
[junit4] 2> 327654 T2392 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=56.3173828125, floorSegmentMB=1.908203125, forceMergeDeletesPctAllowed=23.41566170836658, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7525649374076314
[junit4] 2> 327655 T2392 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7d234ffc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@585e2a11),segFN=segments_1,generation=1}
[junit4] 2> 327655 T2392 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 327660 T2392 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 327660 T2392 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 327660 T2392 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 327661 T2392 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 327661 T2392 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 327661 T2392 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 327661 T2392 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 327661 T2392 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 327662 T2392 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 327662 T2392 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 327662 T2392 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 327662 T2392 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 327663 T2392 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 327663 T2392 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 327663 T2392 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 327664 T2392 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 327664 T2392 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 327666 T2392 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 327670 T2392 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 327670 T2392 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 327671 T2392 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=48, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=59.2548828125, floorSegmentMB=1.7978515625, forceMergeDeletesPctAllowed=14.821505797190378, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 327671 T2392 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7d234ffc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@585e2a11),segFN=segments_1,generation=1}
[junit4] 2> 327671 T2392 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 327672 T2392 oass.SolrIndexSearcher.<init> Opening Searcher@3c3ac44b main
[junit4] 2> 327674 T2393 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3c3ac44b main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 327677 T2392 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 327677 T2329 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 327678 T2329 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 327677 T2396 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52812/_/if collection:collection1 shard:shard2
[junit4] 2> 327679 T2396 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 327684 T2396 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 327685 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 327686 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 327686 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 327686 T2396 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 327687 T2396 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 327687 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> ASYNC NEW_CORE C389 name=collection1 org.apache.solr.core.SolrCore@427abaa1 url=http://127.0.0.1:52812/_/if/collection1 node=127.0.0.1:52812__%2Fif C389_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:52812/_/if, core=collection1, node_name=127.0.0.1:52812__%2Fif}
[junit4] 2> 327687 T2396 C389 P52812 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52812/_/if/collection1/
[junit4] 2> 327687 T2396 C389 P52812 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 327687 T2396 C389 P52812 oasc.SyncStrategy.syncToMe http://127.0.0.1:52812/_/if/collection1/ has no replicas
[junit4] 2> 327687 T2396 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52812/_/if/collection1/ shard2
[junit4] 2> 327688 T2396 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 327689 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 327691 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 327692 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 327752 T2329 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 327753 T2329 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 327755 T2329 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55719
[junit4] 2> 327756 T2329 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 327756 T2329 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 327756 T2329 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1391229270796
[junit4] 2> 327756 T2329 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1391229270796/'
[junit4] 2> 327769 T2329 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1391229270796/solr.xml
[junit4] 2> 327796 T2351 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> 327796 T2373 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> 327796 T2391 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> 327796 T2360 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> 327806 T2329 oasc.CoreContainer.<init> New CoreContainer 2010231535
[junit4] 2> 327806 T2329 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1391229270796/]
[junit4] 2> 327807 T2329 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 327807 T2329 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 327808 T2329 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 327808 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 327808 T2329 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 327808 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 327808 T2329 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 327809 T2329 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 327809 T2329 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 327811 T2329 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 327811 T2329 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 327811 T2329 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 327811 T2329 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59659/solr
[junit4] 2> 327812 T2329 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 327812 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 327814 T2407 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@683aa65d name:ZooKeeperConnection Watcher:127.0.0.1:59659 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 327814 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 327816 T2329 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 327818 T2409 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ffd3e1d name:ZooKeeperConnection Watcher:127.0.0.1:59659/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 327818 T2329 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 327823 T2329 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 327841 T2396 oasc.ZkController.register We are http://127.0.0.1:52812/_/if/collection1/ and leader is http://127.0.0.1:52812/_/if/collection1/
[junit4] 2> 327842 T2396 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52812/_/if
[junit4] 2> 327842 T2396 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 327842 T2396 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 327842 T2396 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 327844 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 327844 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 327844 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 327844 T2396 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 327847 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 327848 T2352 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:52812/_/if",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52812__%2Fif",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 327852 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 327955 T2351 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> 327956 T2391 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> 327956 T2373 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> 327956 T2409 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> 327956 T2360 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> 328826 T2329 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55719__%2Fif
[junit4] 2> 328828 T2329 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55719__%2Fif
[junit4] 2> 328831 T2409 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 328831 T2373 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 328831 T2360 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 328831 T2351 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 328831 T2391 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 328840 T2410 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 328841 T2410 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 328842 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 328842 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 328843 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 328842 T2410 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 328845 T2352 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 328846 T2352 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:55719/_/if",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55719__%2Fif",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 328846 T2352 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 328847 T2352 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 328852 T2351 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 328956 T2409 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> 328956 T2351 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> 328956 T2391 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> 328956 T2373 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> 328956 T2360 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> 329844 T2410 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 329844 T2410 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1391229270796/collection1
[junit4] 2> 329844 T2410 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 329845 T2410 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 329845 T2410 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 329847 T2410 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1391229270796/collection1/'
[junit4] 2> 329848 T2410 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1391229270796/collection1/lib/classes/' to classloader
[junit4] 2> 329848 T2410 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1391229270796/collection1/lib/README' to classloader
[junit4] 2> 329884 T2410 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 329923 T2410 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 329924 T2410 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 329939 T2410 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 330239 T2410 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 330241 T2410 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 330242 T2410 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 330245 T2410 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 330263 T2410 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 330264 T2410 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1391229270796/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty3/
[junit4] 2> 330264 T2410 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2fa45d6
[junit4] 2> 330264 T2410 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty3
[junit4] 2> 330264 T2410 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty3/index/
[junit4] 2> 330265 T2410 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 330265 T2410 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty3/index
[junit4] 2> 330265 T2410 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=56.3173828125, floorSegmentMB=1.908203125, forceMergeDeletesPctAllowed=23.41566170836658, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7525649374076314
[junit4] 2> 330266 T2410 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4a6c2b5d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a8a2980),segFN=segments_1,generation=1}
[junit4] 2> 330266 T2410 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 330269 T2410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 330269 T2410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 330269 T2410 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 330269 T2410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 330270 T2410 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 330270 T2410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 330270 T2410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 330270 T2410 oasup.UpdateRequestProcessorCh
[...truncated too long message...]
onExpiredException: 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:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[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:253)
[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> 538034 T2409 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 538034 T2409 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> 538034 T2409 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 538034 T2409 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:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[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:253)
[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> 538117 T2428 C493 P52107 oasc.SyncStrategy.sync WARN Closed, skipping sync up.
[junit4] 2> 538117 T2428 oasc.ShardLeaderElectionContext.rejoinLeaderElection Not rejoining election because CoreContainer is shutdown
[junit4] 2> 538117 T2428 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@4621484a
[junit4] 2> 538124 T2428 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=4,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=804,cumulative_deletesById=378,cumulative_deletesByQuery=1,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=1}
[junit4] 2> 538124 T2428 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 538124 T2428 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 538125 T2428 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 538126 T2428 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 538126 T2428 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 538126 T2428 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty4 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty4;done=false>>]
[junit4] 2> 538126 T2428 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty4
[junit4] 2> 538126 T2428 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty4/index;done=false>>]
[junit4] 2> 538126 T2428 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-1391229263411/jetty4/index
[junit4] 2> 538127 T2428 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 538127 T2428 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:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[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:253)
[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=Lucene46: {n_ti=Lucene41(blocksize=128), id=Pulsing41(freqCutoff=10 minBlockSize=21 maxBlockSize=64), _version_=PostingsFormat(name=Lucene41WithOrds)}, docValues:{}, sim=DefaultSimilarity, locale=fr_LU, timezone=Europe/Moscow
[junit4] 2> NOTE: Linux 3.8.0-35-generic amd64/Oracle Corporation 1.7.0_51 (64-bit)/cpus=8,threads=1,free=148985560,total=313524224
[junit4] 2> NOTE: All tests run in this JVM: [ReturnFieldsTest, SolrInfoMBeanTest, TestSchemaVersionResource, PolyFieldTest, BasicDistributedZkTest, QueryParsingTest, TestSuggestSpellingConverter, DOMUtilTest, FieldMutatingUpdateProcessorTest, TestSolrXmlPersistence, TestConfig, TestOverriddenPrefixQueryForCustomFieldType, TestClassNameShortening, TestElisionMultitermQuery, HdfsChaosMonkeySafeLeaderTest, CacheHeaderTest, FileBasedSpellCheckerTest, CoreMergeIndexesAdminHandlerTest, TestNoOpRegenerator, TestJmxMonitoredMap, PreAnalyzedUpdateProcessorTest, DistributedTermsComponentTest, BlockCacheTest, TestFileDictionaryLookup, TestGroupingSearch, SOLR749Test, SystemInfoHandlerTest, TestQueryUtils, TestFunctionQuery, TestPerFieldSimilarity, QueryResultKeyTest, TestNRTOpen, TestModifyConfFiles, SliceStateTest, TestSolrXmlPersistor, SliceStateUpdateTest, LegacyHTMLStripCharFilterTest, ShowFileRequestHandlerTest, TestNonNRTOpen, AnalysisAfterCoreReloadTest, TestValueSourceCache, UpdateParamsTest, DistributedDebugComponentTest, URLClassifyProcessorTest, TriLevelCompositeIdRoutingTest, UUIDFieldTest, AbstractAnalyticsStatsTest, TestManagedSchema, SuggesterFSTTest, SuggestComponentTest, ClusterStateTest, TestRemoteStreaming, ResponseLogComponentTest, HdfsSyncSliceTest, InfoHandlerTest, ConnectionManagerTest, TermsComponentTest, JsonLoaderTest, SolrTestCaseJ4Test, OverseerTest, DistributedSpellCheckComponentTest, DocValuesTest, HdfsCollectionsAPIDistributedZkTest, ShardSplitTest]
[junit4] Completed on J0 in 217.93s, 1 test, 1 failure <<< FAILURES!
[...truncated 812 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:453: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:433: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1268: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:901: There were test failures: 365 suites, 1590 tests, 1 failure, 35 ignored (7 assumptions)
Total time: 47 minutes 46 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_51 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_51) - Build #
9316 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9316/
Java: 32bit/jdk1.7.0_51 -server -XX:+UseSerialGC
3 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
Error Message:
Suite timeout exceeded (>= 7200000 msec).
Stack Trace:
java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
at __randomizedtesting.SeedInfo.seed([4019CF490C3A97E0]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
Error Message:
Captured an uncaught exception in thread: Thread[id=1468, name=RecoveryThread, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=1468, name=RecoveryThread, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
Caused by: java.lang.AssertionError: liveDocs.count()=9 info.docCount=10 info.getDelCount()=3
at __randomizedtesting.SeedInfo.seed([4019CF490C3A97E0]:0)
at org.apache.lucene.codecs.lucene40.Lucene40LiveDocsFormat.readLiveDocs(Lucene40LiveDocsFormat.java:92)
at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:103)
at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:131)
at org.apache.lucene.index.ReadersAndUpdates.getReadOnlyClone(ReadersAndUpdates.java:183)
at org.apache.lucene.index.StandardDirectoryReader.open(StandardDirectoryReader.java:97)
at org.apache.lucene.index.IndexWriter.getReader(IndexWriter.java:380)
at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:268)
at org.apache.lucene.index.DirectoryReader.openIfChanged(DirectoryReader.java:204)
at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1444)
at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1632)
at org.apache.solr.handler.SnapPuller.openNewSearcherAndUpdateCommitPoint(SnapPuller.java:670)
at org.apache.solr.handler.SnapPuller.fetchLatestIndex(SnapPuller.java:490)
at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:322)
at org.apache.solr.cloud.RecoveryStrategy.replicate(RecoveryStrategy.java:155)
at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:437)
at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:247)
REGRESSION: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch
Error Message:
Test abandoned because suite timeout was reached.
Stack Trace:
java.lang.Exception: Test abandoned because suite timeout was reached.
at __randomizedtesting.SeedInfo.seed([4019CF490C3A97E0]:0)
Build Log:
[...truncated 10944 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4] 2> 486296 T958 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /raqc/w
[junit4] 2> 486301 T958 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-ChaosMonkeySafeLeaderTest-1391235271578
[junit4] 2> 486302 T958 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 486302 T959 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 486402 T958 oasc.ZkTestServer.run start zk server on port:49228
[junit4] 2> 486403 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 486472 T965 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b05d name:ZooKeeperConnection Watcher:127.0.0.1:49228 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 486473 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 486473 T958 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 486478 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 486479 T967 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@afa335 name:ZooKeeperConnection Watcher:127.0.0.1:49228/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 486479 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 486480 T958 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 486483 T958 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 486485 T958 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 486487 T958 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 486490 T958 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 486490 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 486495 T958 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 486495 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 486499 T958 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 486499 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 486502 T958 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 486502 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 486505 T958 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 486506 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 486508 T958 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 486509 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 486512 T958 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 486512 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 486515 T958 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 486516 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 486519 T958 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 486519 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 486522 T958 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 486523 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 486526 T958 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 486527 T958 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 486607 T958 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 486613 T958 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:38075
[junit4] 2> 486613 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 486613 T958 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 486614 T958 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1391235271806
[junit4] 2> 486614 T958 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1391235271806/'
[junit4] 2> 486623 T958 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1391235271806/solr.xml
[junit4] 2> 486654 T958 oasc.CoreContainer.<init> New CoreContainer 27837872
[junit4] 2> 486655 T958 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1391235271806/]
[junit4] 2> 486656 T958 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 486656 T958 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 486656 T958 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 486657 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 486657 T958 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 486657 T958 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 486657 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 486658 T958 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 486658 T958 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 486660 T958 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 486660 T958 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 486661 T958 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 486661 T958 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49228/solr
[junit4] 2> 486661 T958 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 486662 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 486664 T978 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14ae32f name:ZooKeeperConnection Watcher:127.0.0.1:49228 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 486665 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 486666 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 486667 T980 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c60d45 name:ZooKeeperConnection Watcher:127.0.0.1:49228/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 486668 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 486669 T958 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 486672 T958 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 486674 T958 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 486676 T958 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38075_raqc%2Fw
[junit4] 2> 486676 T958 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38075_raqc%2Fw
[junit4] 2> 486679 T958 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 486680 T958 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 486683 T958 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38075_raqc%2Fw
[junit4] 2> 486684 T958 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 486685 T958 oasc.Overseer.start Overseer (id=91175994758266883-127.0.0.1:38075_raqc%2Fw-n_0000000000) starting
[junit4] 2> 486688 T958 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 486690 T982 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 486690 T958 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 486691 T982 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 486694 T958 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 486695 T958 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 486698 T981 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 486700 T983 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 486700 T983 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 486702 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 486702 T983 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 486703 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 486704 T981 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:38075/raqc/w",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:38075_raqc%2Fw",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 486704 T981 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 486704 T981 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 486707 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 486707 T980 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> 487703 T983 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 487703 T983 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1391235271806/collection1
[junit4] 2> 487703 T983 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 487704 T983 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 487704 T983 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 487705 T983 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1391235271806/collection1/'
[junit4] 2> 487706 T983 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1391235271806/collection1/lib/classes/' to classloader
[junit4] 2> 487706 T983 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1391235271806/collection1/lib/README' to classloader
[junit4] 2> 487735 T983 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 487766 T983 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 487767 T983 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 487772 T983 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 488057 T983 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 488060 T983 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 488061 T983 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 488064 T983 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 488085 T983 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 488091 T983 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1391235271806/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/control/data/
[junit4] 2> 488091 T983 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1594bee
[junit4] 2> 488092 T983 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/control/data
[junit4] 2> 488092 T983 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/control/data/index/
[junit4] 2> 488092 T983 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 488093 T983 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/control/data/index
[junit4] 2> 488093 T983 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=40, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8770342208481783]
[junit4] 2> 488095 T983 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 488095 T983 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 488098 T983 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 488098 T983 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 488099 T983 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 488099 T983 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 488099 T983 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 488099 T983 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 488100 T983 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 488100 T983 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 488100 T983 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 488100 T983 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 488101 T983 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 488101 T983 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 488101 T983 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 488101 T983 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 488102 T983 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 488102 T983 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 488102 T983 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 488104 T983 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 488106 T983 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 488106 T983 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 488107 T983 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 488108 T983 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 488108 T983 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 488108 T983 oass.SolrIndexSearcher.<init> Opening Searcher@1adb229 main
[junit4] 2> 488110 T984 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1adb229 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 488111 T983 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 488112 T958 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 488112 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 488112 T987 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:38075/raqc/w collection:control_collection shard:shard1
[junit4] 2> 488113 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 488114 T987 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 488114 T989 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@aa30ca name:ZooKeeperConnection Watcher:127.0.0.1:49228/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 488114 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 488116 T958 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 488118 T958 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 488120 T987 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 488122 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 488123 T987 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 488123 T987 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C2525 name=collection1 org.apache.solr.core.SolrCore@92039 url=http://127.0.0.1:38075/raqc/w/collection1 node=127.0.0.1:38075_raqc%2Fw C2525_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:38075/raqc/w, core=collection1, node_name=127.0.0.1:38075_raqc%2Fw}
[junit4] 2> 488123 T987 C2525 P38075 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:38075/raqc/w/collection1/
[junit4] 2> 488123 T987 C2525 P38075 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 488124 T987 C2525 P38075 oasc.SyncStrategy.syncToMe http://127.0.0.1:38075/raqc/w/collection1/ has no replicas
[junit4] 2> 488124 T987 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:38075/raqc/w/collection1/ shard1
[junit4] 2> 488124 T987 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 488125 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 488129 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 488130 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 488133 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 488186 T958 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 488187 T958 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 488189 T958 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:48883
[junit4] 2> 488189 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 488190 T958 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 488190 T958 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1391235273395
[junit4] 2> 488190 T958 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1391235273395/'
[junit4] 2> 488200 T958 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1391235273395/solr.xml
[junit4] 2> 488231 T958 oasc.CoreContainer.<init> New CoreContainer 8097678
[junit4] 2> 488231 T958 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1391235273395/]
[junit4] 2> 488232 T958 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 488232 T958 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 488233 T958 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 488233 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 488233 T958 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 488233 T958 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 488234 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 488234 T958 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 488234 T958 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 488236 T989 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> 488236 T980 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> 488238 T958 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 488238 T958 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 488238 T958 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 488239 T958 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49228/solr
[junit4] 2> 488239 T958 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 488240 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 488241 T1000 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e1bf21 name:ZooKeeperConnection Watcher:127.0.0.1:49228 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 488241 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 488243 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 488244 T1002 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29c9b7 name:ZooKeeperConnection Watcher:127.0.0.1:49228/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 488244 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 488247 T958 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 488281 T987 oasc.ZkController.register We are http://127.0.0.1:38075/raqc/w/collection1/ and leader is http://127.0.0.1:38075/raqc/w/collection1/
[junit4] 2> 488281 T987 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38075/raqc/w
[junit4] 2> 488282 T987 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 488282 T987 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 488282 T987 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 488283 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 488283 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 488283 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 488284 T987 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 488285 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 488286 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:38075/raqc/w",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:38075_raqc%2Fw",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 488288 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 488391 T1002 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> 488391 T980 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> 488391 T989 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> 489250 T958 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48883_raqc%2Fw
[junit4] 2> 489251 T958 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48883_raqc%2Fw
[junit4] 2> 489253 T989 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 489254 T1002 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 489254 T980 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 489259 T1003 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 489259 T1003 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 489260 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 489260 T1003 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 489260 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 489260 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 489262 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 489263 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:48883/raqc/w",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:48883_raqc%2Fw",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 489263 T981 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 489263 T981 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 489265 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 489368 T980 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> 489368 T1002 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> 489368 T989 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> 490260 T1003 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 490261 T1003 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1391235273395/collection1
[junit4] 2> 490261 T1003 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 490261 T1003 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 490262 T1003 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 490263 T1003 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1391235273395/collection1/'
[junit4] 2> 490263 T1003 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1391235273395/collection1/lib/classes/' to classloader
[junit4] 2> 490263 T1003 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1391235273395/collection1/lib/README' to classloader
[junit4] 2> 490292 T1003 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 490334 T1003 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 490335 T1003 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 490340 T1003 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 490617 T1003 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 490619 T1003 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 490620 T1003 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 490623 T1003 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 490644 T1003 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 490644 T1003 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1391235273395/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty1/
[junit4] 2> 490644 T1003 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1594bee
[junit4] 2> 490645 T1003 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty1
[junit4] 2> 490645 T1003 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty1/index/
[junit4] 2> 490645 T1003 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 490646 T1003 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty1/index
[junit4] 2> 490646 T1003 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=40, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8770342208481783]
[junit4] 2> 490648 T1003 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 490648 T1003 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 490652 T1003 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 490652 T1003 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 490652 T1003 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 490653 T1003 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 490653 T1003 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 490653 T1003 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 490653 T1003 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 490654 T1003 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 490654 T1003 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 490654 T1003 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 490655 T1003 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 490655 T1003 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 490655 T1003 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 490655 T1003 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 490656 T1003 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 490656 T1003 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 490657 T1003 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 490659 T1003 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 490661 T1003 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 490661 T1003 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 490661 T1003 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 490662 T1003 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 490662 T1003 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 490663 T1003 oass.SolrIndexSearcher.<init> Opening Searcher@184123f main
[junit4] 2> 490666 T1004 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@184123f main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 490668 T1003 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 490669 T958 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 490669 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 490669 T1007 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48883/raqc/w collection:collection1 shard:shard3
[junit4] 2> 490671 T1007 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 490675 T1007 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
[junit4] 2> 490677 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 490677 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 490677 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 490677 T1007 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 490677 T1007 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C2526 name=collection1 org.apache.solr.core.SolrCore@3ca839 url=http://127.0.0.1:48883/raqc/w/collection1 node=127.0.0.1:48883_raqc%2Fw C2526_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:48883/raqc/w, core=collection1, node_name=127.0.0.1:48883_raqc%2Fw}
[junit4] 2> 490678 T1007 C2526 P48883 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:48883/raqc/w/collection1/
[junit4] 2> 490678 T1007 C2526 P48883 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 490678 T1007 C2526 P48883 oasc.SyncStrategy.syncToMe http://127.0.0.1:48883/raqc/w/collection1/ has no replicas
[junit4] 2> 490678 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 490678 T1007 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:48883/raqc/w/collection1/ shard3
[junit4] 2> 490678 T1007 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 490682 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 490686 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 490690 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 490738 T958 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 490739 T958 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 490741 T958 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58650
[junit4] 2> 490741 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 490741 T958 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 490742 T958 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1391235275946
[junit4] 2> 490742 T958 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1391235275946/'
[junit4] 2> 490752 T958 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1391235275946/solr.xml
[junit4] 2> 490782 T958 oasc.CoreContainer.<init> New CoreContainer 6272125
[junit4] 2> 490783 T958 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1391235275946/]
[junit4] 2> 490784 T958 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 490784 T958 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 490784 T958 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 490785 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 490785 T958 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 490785 T958 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 490785 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 490786 T958 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 490786 T958 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 490788 T958 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 490788 T958 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 490789 T958 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 490789 T958 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49228/solr
[junit4] 2> 490789 T958 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 490790 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 490791 T1018 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@142a4cb name:ZooKeeperConnection Watcher:127.0.0.1:49228 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 490792 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 490793 T980 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> 490793 T989 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> 490793 T1002 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> 490795 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 490797 T1020 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c5197f name:ZooKeeperConnection Watcher:127.0.0.1:49228/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 490797 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 490800 T958 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 490837 T1007 oasc.ZkController.register We are http://127.0.0.1:48883/raqc/w/collection1/ and leader is http://127.0.0.1:48883/raqc/w/collection1/
[junit4] 2> 490838 T1007 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48883/raqc/w
[junit4] 2> 490838 T1007 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 490838 T1007 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 490838 T1007 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 490839 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 490839 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 490839 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 490839 T1007 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 490841 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 490841 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:48883/raqc/w",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:48883_raqc%2Fw",
[junit4] 2> "shard":"shard3",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 490844 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 490946 T989 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> 490946 T1002 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> 490946 T1020 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> 490946 T980 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> 491803 T958 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58650_raqc%2Fw
[junit4] 2> 491805 T958 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58650_raqc%2Fw
[junit4] 2> 491808 T989 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 491808 T1002 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 491808 T1020 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 491808 T980 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 491813 T1021 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 491814 T1021 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 491815 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 491815 T1021 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 491815 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 491815 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 491816 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 491817 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:58650/raqc/w",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:58650_raqc%2Fw",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 491817 T981 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 491817 T981 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 491819 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 491921 T980 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> 491921 T1020 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> 491921 T1002 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> 491921 T989 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> 492815 T1021 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 492816 T1021 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1391235275946/collection1
[junit4] 2> 492816 T1021 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 492816 T1021 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 492817 T1021 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 492818 T1021 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1391235275946/collection1/'
[junit4] 2> 492818 T1021 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1391235275946/collection1/lib/classes/' to classloader
[junit4] 2> 492818 T1021 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1391235275946/collection1/lib/README' to classloader
[junit4] 2> 492857 T1021 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 492899 T1021 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 492901 T1021 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 492906 T1021 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 493183 T1021 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 493185 T1021 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 493186 T1021 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 493190 T1021 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 493209 T1021 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 493209 T1021 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1391235275946/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty2/
[junit4] 2> 493210 T1021 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1594bee
[junit4] 2> 493210 T1021 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty2
[junit4] 2> 493210 T1021 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty2/index/
[junit4] 2> 493211 T1021 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 493211 T1021 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty2/index
[junit4] 2> 493211 T1021 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=40, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8770342208481783]
[junit4] 2> 493214 T1021 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 493214 T1021 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 493217 T1021 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 493218 T1021 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 493218 T1021 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 493218 T1021 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 493218 T1021 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 493218 T1021 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 493219 T1021 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 493219 T1021 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 493219 T1021 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 493220 T1021 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 493220 T1021 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 493220 T1021 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 493220 T1021 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 493221 T1021 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 493221 T1021 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 493222 T1021 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 493222 T1021 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 493224 T1021 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 493226 T1021 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 493226 T1021 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 493227 T1021 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 493228 T1021 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 493228 T1021 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 493228 T1021 oass.SolrIndexSearcher.<init> Opening Searcher@101c10b main
[junit4] 2> 493231 T1022 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@101c10b main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 493233 T1021 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 493234 T958 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 493234 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 493234 T1025 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58650/raqc/w collection:collection1 shard:shard2
[junit4] 2> 493235 T1025 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 493240 T1025 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 493241 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 493242 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 493242 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 493242 T1025 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 493242 T1025 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C2527 name=collection1 org.apache.solr.core.SolrCore@183b1a4 url=http://127.0.0.1:58650/raqc/w/collection1 node=127.0.0.1:58650_raqc%2Fw C2527_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:58650/raqc/w, core=collection1, node_name=127.0.0.1:58650_raqc%2Fw}
[junit4] 2> 493242 T1025 C2527 P58650 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58650/raqc/w/collection1/
[junit4] 2> 493243 T1025 C2527 P58650 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 493243 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 493243 T1025 C2527 P58650 oasc.SyncStrategy.syncToMe http://127.0.0.1:58650/raqc/w/collection1/ has no replicas
[junit4] 2> 493243 T1025 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58650/raqc/w/collection1/ shard2
[junit4] 2> 493243 T1025 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 493245 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 493248 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 493250 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 493305 T958 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 493305 T958 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 493307 T958 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:43392
[junit4] 2> 493308 T958 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 493308 T958 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 493309 T958 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1391235278510
[junit4] 2> 493309 T958 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1391235278510/'
[junit4] 2> 493319 T958 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1391235278510/solr.xml
[junit4] 2> 493349 T958 oasc.CoreContainer.<init> New CoreContainer 28453865
[junit4] 2> 493350 T958 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1391235278510/]
[junit4] 2> 493351 T958 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 493351 T958 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 493351 T958 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 493351 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 493352 T958 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 493352 T958 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 493352 T958 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 493353 T958 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 493353 T958 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 493354 T1002 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> 493354 T1020 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> 493354 T980 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> 493354 T989 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> 493355 T958 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 493355 T958 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 493356 T958 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 493356 T958 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49228/solr
[junit4] 2> 493356 T958 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 493357 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 493358 T1036 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f0956b name:ZooKeeperConnection Watcher:127.0.0.1:49228 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 493359 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 493362 T958 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 493362 T1038 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16bd8ad name:ZooKeeperConnection Watcher:127.0.0.1:49228/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 493362 T958 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 493366 T958 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 493399 T1025 oasc.ZkController.register We are http://127.0.0.1:58650/raqc/w/collection1/ and leader is http://127.0.0.1:58650/raqc/w/collection1/
[junit4] 2> 493399 T1025 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58650/raqc/w
[junit4] 2> 493399 T1025 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 493399 T1025 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 493399 T1025 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 493400 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 493401 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 493401 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 493401 T1025 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 493402 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 493403 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:58650/raqc/w",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:58650_raqc%2Fw",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 493405 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 493507 T1002 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> 493507 T980 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> 493507 T1038 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> 493507 T989 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> 493507 T1020 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> 494369 T958 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43392_raqc%2Fw
[junit4] 2> 494370 T958 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43392_raqc%2Fw
[junit4] 2> 494373 T989 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 494373 T1002 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 494373 T980 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 494373 T1038 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 494373 T1020 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 494391 T1039 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 494391 T1039 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 494392 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 494392 T1039 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 494393 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 494393 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 494394 T981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 494395 T981 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:43392/raqc/w",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:43392_raqc%2Fw",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 494395 T981 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 494395 T981 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 494397 T980 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 494500 T1020 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> 494500 T980 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> 494500 T1038 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> 494500 T1002 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> 494500 T989 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> 495393 T1039 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 495393 T1039 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1391235278510/collection1
[junit4] 2> 495393 T1039 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 495394 T1039 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 495394 T1039 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 495395 T1039 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1391235278510/collection1/'
[junit4] 2> 495396 T1039 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1391235278510/collection1/lib/classes/' to classloader
[junit4] 2> 495396 T1039 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1391235278510/collection1/lib/README' to classloader
[junit4] 2> 495426 T1039 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 495459 T1039 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 495460 T1039 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 495465 T1039 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 495747 T1039 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 495750 T1039 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 495751 T1039 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 495754 T1039 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 495771 T1039 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 495771 T1039 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1391235278510/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty3/
[junit4] 2> 495772 T1039 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1594bee
[junit4] 2> 495772 T1039 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty3
[junit4] 2> 495772 T1039 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty3/index/
[junit4] 2> 495772 T1039 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 495773 T1039 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty3/index
[junit4] 2> 495773 T1039 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=40, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8770342208481783]
[junit4] 2> 495775 T1039 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 495775 T1039 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 495779 T1039 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 495779 T1039 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 495779 T1039 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 495779 T1039 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 495780 T1039 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 495780 T1039 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 495780 T1039 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 495780 T1039 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 495781 T1039 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 495781 T1039 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 495781 T1039 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 495782 T1039 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 495782 T1039 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 495782 T1039 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 495783 T1039 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 495783 T1039 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 495783 T1039 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 495785 T1039 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 495787 T1039 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 495787 T1039 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 495788 T1039 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 495789 T1039 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1391235271577/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 495789 T1039 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 495789 T1039 oass.SolrIndexSearcher.<init> Opening Searcher@1f09ebd main
[junit4] 2> 495793 T1040 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1f09ebd main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 495795 T1039 oasc.Cor
[...truncated too long message...]
tProvider.next(StaticHostProvider.java:86)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:937)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:993)
[junit4] 2> 61) Thread[id=1428, name=HashSessionScavenger-41, state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:552)
[junit4] 2> at java.util.TimerThread.run(Timer.java:505)
[junit4] 2> 62) Thread[id=1080, name=coreZkRegister-681-thread-1, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
[junit4] 2> at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 63) Thread[id=1236, name=commitScheduler-728-thread-1, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
[junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1079)
[junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 64) Thread[id=1391, name=searcherExecutor-799-thread-1, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
[junit4] 2> at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 65) Thread[id=1377, name=HashSessionScavenger-39, state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:552)
[junit4] 2> at java.util.TimerThread.run(Timer.java:505)
[junit4] 2> 66) Thread[id=1469, name=HashSessionScavenger-43, state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:552)
[junit4] 2> at java.util.TimerThread.run(Timer.java:505)
[junit4] 2> 67) Thread[id=1142, name=HashSessionScavenger-32, state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:552)
[junit4] 2> at java.util.TimerThread.run(Timer.java:505)
[junit4] 2> 68) Thread[id=1118, name=Thread-464, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.lang.Object.wait(Object.java:503)
[junit4] 2> at org.apache.solr.core.CloserThread.run(CoreContainer.java:1014)
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=DefaultSimilarity, locale=ja_JP_JP_#u-ca-japanese, timezone=Asia/Dushanbe
[junit4] 2> NOTE: Linux 3.8.0-35-generic i386/Oracle Corporation 1.7.0_51 (32-bit)/cpus=8,threads=82,free=120446240,total=323854336
[junit4] 2> NOTE: All tests run in this JVM: [DistribCursorPagingTest, LeaderElectionIntegrationTest, NoFacetTest, TestSchemaSimilarityResource, DirectUpdateHandlerTest, ZkSolrClientTest, TimeZoneUtilsTest, TestRecovery, SimplePostToolTest, TestBinaryField, StandardRequestHandlerTest, StatsComponentTest, AbstractAnalyticsFacetTest, TestSolrJ, TestDistributedGrouping, TestInfoStreamLogging, TestCopyFieldCollectionResource, DirectSolrConnectionTest, TestRecoveryHdfs, QueryFacetTest, TestUpdate, DocValuesMultiTest, UniqFieldsUpdateProcessorFactoryTest, TestMultiCoreConfBootstrap, TestFastOutputStream, TestZkChroot, FunctionTest, XmlUpdateRequestHandlerTest, TestCSVLoader, BadCopyFieldTest, RangeFacetTest, TestSweetSpotSimilarityFactory, TestAnalyzedSuggestions, TestCustomSort, AliasIntegrationTest, StressHdfsTest, TestFieldResource, ChaosMonkeySafeLeaderTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.seed=4019CF490C3A97E0 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ja_JP_JP_#u-ca-japanese -Dtests.timezone=Asia/Dushanbe -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s J1 | ChaosMonkeySafeLeaderTest (suite) <<<
[junit4] > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
[junit4] > at __randomizedtesting.SeedInfo.seed([4019CF490C3A97E0]:0)Throwable #2: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=1468, name=RecoveryThread, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4] > Caused by: java.lang.AssertionError: liveDocs.count()=9 info.docCount=10 info.getDelCount()=3
[junit4] > at __randomizedtesting.SeedInfo.seed([4019CF490C3A97E0]:0)
[junit4] > at org.apache.lucene.codecs.lucene40.Lucene40LiveDocsFormat.readLiveDocs(Lucene40LiveDocsFormat.java:92)
[junit4] > at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:103)
[junit4] > at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:131)
[junit4] > at org.apache.lucene.index.ReadersAndUpdates.getReadOnlyClone(ReadersAndUpdates.java:183)
[junit4] > at org.apache.lucene.index.StandardDirectoryReader.open(StandardDirectoryReader.java:97)
[junit4] > at org.apache.lucene.index.IndexWriter.getReader(IndexWriter.java:380)
[junit4] > at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:268)
[junit4] > at org.apache.lucene.index.DirectoryReader.openIfChanged(DirectoryReader.java:204)
[junit4] > at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1444)
[junit4] > at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1632)
[junit4] > at org.apache.solr.handler.SnapPuller.openNewSearcherAndUpdateCommitPoint(SnapPuller.java:670)
[junit4] > at org.apache.solr.handler.SnapPuller.fetchLatestIndex(SnapPuller.java:490)
[junit4] > at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:322)
[junit4] > at org.apache.solr.cloud.RecoveryStrategy.replicate(RecoveryStrategy.java:155)
[junit4] > at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:437)
[junit4] > at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:247)
[junit4] Completed on J1 in 7224.76s, 1 test, 3 errors <<< FAILURES!
[...truncated 167 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:453: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:433: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1268: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:901: There were test failures: 365 suites, 1590 tests, 2 suite-level errors, 1 error, 290 ignored (5 assumptions)
Total time: 153 minutes 27 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_51 -server -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure