Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/11370/ Java: 64bit/jdk1.8.0_40-ea-b04 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed. FAILED: org.apache.solr.cloud.LeaderInitiatedRecoveryOnCommitTest.testDistribSearch Error Message: Server refused connection at: http://127.0.0.1:39565 Stack Trace: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: http://127.0.0.1:39565 at __randomizedtesting.SeedInfo.seed([3C3623CE94700F57:BDD0ADD6E32F6F6B]:0) at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:578) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:215) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:211) at org.apache.solr.cloud.BasicDistributedZkTest.createCollection(BasicDistributedZkTest.java:612) at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1579) at org.apache.solr.cloud.LeaderInitiatedRecoveryOnCommitTest.multiShardTest(LeaderInitiatedRecoveryOnCommitTest.java:77) at org.apache.solr.cloud.LeaderInitiatedRecoveryOnCommitTest.doTest(LeaderInitiatedRecoveryOnCommitTest.java:71) at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:483) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836) at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738) at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) at java.lang.Thread.run(Thread.java:745) Caused by: java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:345) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:589) at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:117) at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:178) at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:304) at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:610) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:445) at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:863) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57) at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:466) ... 47 more Build Log: [...truncated 11837 lines...] [junit4] Suite: org.apache.solr.cloud.LeaderInitiatedRecoveryOnCommitTest [junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/init-core-data-001 [junit4] 2> 2393700 T8027 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: / [junit4] 2> 2393702 T8027 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch [junit4] 2> 2393703 T8027 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 2393703 T8028 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 2393803 T8027 oasc.ZkTestServer.run start zk server on port:49087 [junit4] 2> 2393804 T8027 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 2393805 T8027 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2393806 T8034 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@79d99290 name:ZooKeeperConnection Watcher:127.0.0.1:49087 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2393806 T8027 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2393806 T8027 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 2393807 T8027 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 2393809 T8027 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 2393809 T8027 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2393810 T8036 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@423bfbec name:ZooKeeperConnection Watcher:127.0.0.1:49087/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2393810 T8027 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2393810 T8027 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 2393811 T8027 oascc.SolrZkClient.makePath makePath: /collections/collection1 [junit4] 2> 2393812 T8027 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards [junit4] 2> 2393814 T8027 oascc.SolrZkClient.makePath makePath: /collections/control_collection [junit4] 2> 2393814 T8027 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards [junit4] 2> 2393815 T8027 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4] 2> 2393816 T8027 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml [junit4] 2> 2393818 T8027 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml [junit4] 2> 2393818 T8027 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml [junit4] 2> 2393819 T8027 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 2393820 T8027 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 2393821 T8027 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt [junit4] 2> 2393821 T8027 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt [junit4] 2> 2393822 T8027 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt [junit4] 2> 2393822 T8027 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt [junit4] 2> 2393823 T8027 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml [junit4] 2> 2393824 T8027 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml [junit4] 2> 2393824 T8027 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml [junit4] 2> 2393825 T8027 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml [junit4] 2> 2393826 T8027 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json [junit4] 2> 2393826 T8027 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json [junit4] 2> 2393827 T8027 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 2393827 T8027 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 2393828 T8027 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4] 2> 2393828 T8027 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt [junit4] 2> 2393829 T8027 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt [junit4] 2> 2393830 T8027 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt [junit4] 2> 2394076 T8027 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 2394081 T8027 oejs.AbstractConnector.doStart Started [email protected]:41169 [junit4] 2> 2394082 T8027 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 2394082 T8027 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 2394083 T8027 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-002 [junit4] 2> 2394083 T8027 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-002/' [junit4] 2> 2394101 T8027 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-002/solr.xml [junit4] 2> 2394107 T8027 oasc.CoreContainer.<init> New CoreContainer 475728834 [junit4] 2> 2394108 T8027 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-002/] [junit4] 2> 2394108 T8027 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 2394109 T8027 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 2394109 T8027 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 2394109 T8027 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 2394109 T8027 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 2394109 T8027 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 2394110 T8027 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 2394110 T8027 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 2394110 T8027 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 2394111 T8027 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 2394111 T8027 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 2394111 T8027 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 2394111 T8027 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 2394112 T8027 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49087/solr [junit4] 2> 2394112 T8027 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 2394112 T8027 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 2394113 T8027 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2394114 T8047 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4cdd2853 name:ZooKeeperConnection Watcher:127.0.0.1:49087 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2394114 T8027 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2394114 T8027 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 2394115 T8027 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2394116 T8049 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b5a9f7d name:ZooKeeperConnection Watcher:127.0.0.1:49087/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2394116 T8027 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2394117 T8027 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 2394119 T8027 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 2394120 T8027 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 2394121 T8027 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 2394122 T8027 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 2394123 T8027 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 2394124 T8027 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37001_ [junit4] 2> 2394124 T8027 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37001_ [junit4] 2> 2394125 T8027 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 2394126 T8027 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 2394127 T8027 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 2394128 T8027 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:37001_ [junit4] 2> 2394128 T8027 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 2394129 T8027 oasc.Overseer.start Overseer (id=92553955021422595-127.0.0.1:37001_-n_0000000000) starting [junit4] 2> 2394130 T8027 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 2394133 T8027 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 2394133 T8051 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 2394133 T8027 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 2394134 T8027 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 2394135 T8027 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 2394136 T8050 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 2394138 T8053 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection [junit4] 2> 2394138 T8053 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 2394139 T8053 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 2394139 T8054 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2394140 T8050 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "core":"collection1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:37001";, [junit4] 2> "node_name":"127.0.0.1:37001_", [junit4] 2> "numShards":"1", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"control_collection", [junit4] 2> "operation":"state"} [junit4] 2> 2394141 T8050 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1] [junit4] 2> 2394141 T8050 oasc.Overseer$ClusterStateUpdater.createCollection state version control_collection 1 [junit4] 2> 2394141 T8050 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 2394143 T8054 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> 2395139 T8053 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 2395139 T8053 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection [junit4] 2> 2395140 T8053 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 2395140 T8053 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection [junit4] 2> 2395140 T8053 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper [junit4] 2> 2395141 T8053 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-002/collection1/' [junit4] 2> 2395141 T8053 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-002/collection1/lib/.svn/' to classloader [junit4] 2> 2395141 T8053 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-002/collection1/lib/classes/' to classloader [junit4] 2> 2395141 T8053 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-002/collection1/lib/README' to classloader [junit4] 2> 2395157 T8053 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0 [junit4] 2> 2395172 T8053 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 2395173 T8053 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml [junit4] 2> 2395177 T8053 oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 2395291 T8053 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 2395300 T8053 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 2395301 T8053 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 2395308 T8053 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 2395310 T8053 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 2395312 T8053 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 2395313 T8053 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 2395313 T8053 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 2395313 T8053 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 2395314 T8053 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 2395314 T8053 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 2395314 T8053 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection [junit4] 2> 2395315 T8053 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 2395315 T8053 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-002/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-001/control/data/ [junit4] 2> 2395315 T8053 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1c05a4fa [junit4] 2> 2395316 T8053 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-001/control/data [junit4] 2> 2395316 T8053 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-001/control/data/index/ [junit4] 2> 2395316 T8053 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-001/control/data/index' doesn't exist. Creating new index... [junit4] 2> 2395316 T8053 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-001/control/data/index [junit4] 2> 2395317 T8053 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3323435406429077] [junit4] 2> 2395317 T8053 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-4994249e)),segFN=segments_1,generation=1} [junit4] 2> 2395317 T8053 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 2395319 T8053 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 2395320 T8053 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 2395320 T8053 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 2395320 T8053 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 2395320 T8053 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 2395320 T8053 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 2395320 T8053 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 2395321 T8053 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 2395321 T8053 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 2395321 T8053 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 2395321 T8053 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 2395322 T8053 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 2395322 T8053 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 2395322 T8053 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 2395322 T8053 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 2395322 T8053 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 2395323 T8053 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 2395323 T8053 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 2395323 T8053 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 2395323 T8053 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 2395325 T8053 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 2395326 T8053 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 2395326 T8053 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 2395327 T8053 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 2395328 T8053 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 2395328 T8053 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 2395329 T8053 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=25, maxMergedSegmentMB=31.357421875, floorSegmentMB=0.748046875, forceMergeDeletesPctAllowed=4.7190611138423835, segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2709423214829504 [junit4] 2> 2395329 T8053 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-4994249e)),segFN=segments_1,generation=1} [junit4] 2> 2395329 T8053 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 2395330 T8053 oass.SolrIndexSearcher.<init> Opening Searcher@34089b4[collection1] main [junit4] 2> 2395330 T8053 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection [junit4] 2> 2395331 T8053 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper [junit4] 2> 2395331 T8053 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 2395331 T8053 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2395331 T8053 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 2395331 T8053 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2395332 T8053 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json [junit4] 2> 2395332 T8053 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2395332 T8053 oascc.SolrZkClient.makePath makePath: /configs/conf1/_rest_managed.json [junit4] 2> 2395333 T8053 oasr.ManagedResourceStorage$ZooKeeperStorageIO$1.close Wrote 38 bytes to new znode /configs/conf1/_rest_managed.json [junit4] 2> 2395333 T8053 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2395334 T8053 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 2395335 T8055 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@34089b4[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2395336 T8053 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 2395336 T8058 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:37001 collection:control_collection shard:shard1 [junit4] 2> 2395337 T8027 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0 [junit4] 2> 2395337 T8058 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election [junit4] 2> 2395337 T8027 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 2395338 T8027 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 2395339 T8027 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2395340 T8061 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@42e6310a name:ZooKeeperConnection Watcher:127.0.0.1:49087/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2395340 T8027 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2395340 T8058 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1 [junit4] 2> 2395340 T8027 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 2395341 T8027 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 2395341 T8054 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2395341 T8058 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue. [junit4] 2> 2395342 T8058 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync [junit4] 2> ASYNC NEW_CORE C5949 name=collection1 org.apache.solr.core.SolrCore@31211790 url=http://127.0.0.1:37001/collection1 node=127.0.0.1:37001_ C5949_STATE=coll:control_collection core:collection1 props:{core=collection1, base_url=http://127.0.0.1:37001, node_name=127.0.0.1:37001_, state=down} [junit4] 2> 2395342 T8058 C5949 P37001 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:37001/collection1/ [junit4] 2> 2395342 T8058 C5949 P37001 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me [junit4] 2> 2395342 T8058 C5949 P37001 oasc.SyncStrategy.syncToMe http://127.0.0.1:37001/collection1/ has no replicas [junit4] 2> 2395342 T8058 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:37001/collection1/ shard1 [junit4] 2> 2395343 T8058 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1 [junit4] 2> 2395343 T8027 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false [junit4] 2> 2395344 T8027 oasc.AbstractFullDistribZkTestBase.createJettys Creating collection1 with stateFormat=2 [junit4] 2> 2395344 T8027 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 2395344 T8027 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2395345 T8063 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4dc8ff5c name:ZooKeeperConnection Watcher:127.0.0.1:49087/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2395345 T8027 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2395345 T8054 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2395346 T8027 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 2395347 T8050 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: collection1 [junit4] 2> 2395348 T8050 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1] [junit4] 2> 2395348 T8050 oasc.Overseer$ClusterStateUpdater.createCollection state version collection1 2 [junit4] 2> 2395349 T8054 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2395349 T8050 oasc.Overseer$ClusterStateUpdater.updateZkStates going to create_collection /collections/collection1/state.json [junit4] 2> 2395350 T8054 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> 2395350 T8064 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> 2395396 T8058 oasc.ZkController.register We are http://127.0.0.1:37001/collection1/ and leader is http://127.0.0.1:37001/collection1/ [junit4] 2> 2395396 T8058 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:37001 [junit4] 2> 2395396 T8058 oasc.ZkController.checkRecovery I am the leader, no recovery necessary [junit4] 2> 2395397 T8058 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection [junit4] 2> 2395397 T8058 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 2395398 T8054 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2395400 T8050 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "core":"collection1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:37001";, [junit4] 2> "node_name":"127.0.0.1:37001_", [junit4] 2> "numShards":"1", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"control_collection", [junit4] 2> "operation":"state"} [junit4] 2> 2395502 T8064 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> 2395502 T8054 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> 2395605 T8027 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1 [junit4] 2> 2395605 T8027 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 2395607 T8027 oejs.AbstractConnector.doStart Started [email protected]:48512 [junit4] 2> 2395608 T8027 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 2395608 T8027 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 2395608 T8027 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-003 [junit4] 2> 2395608 T8027 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-003/' [junit4] 2> 2395619 T8027 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-003/solr.xml [junit4] 2> 2395649 T8027 oasc.CoreContainer.<init> New CoreContainer 1420901372 [junit4] 2> 2395649 T8027 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-003/] [junit4] 2> 2395649 T8027 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 2395650 T8027 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 2395650 T8027 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 2395650 T8027 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 2395651 T8027 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 2395651 T8027 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 2395651 T8027 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 2395651 T8027 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 2395652 T8027 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 2395652 T8027 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 2395652 T8027 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 2395653 T8027 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 2395653 T8027 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 2395653 T8027 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49087/solr [junit4] 2> 2395654 T8027 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 2395654 T8027 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 2395655 T8027 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2395655 T8075 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@48967c80 name:ZooKeeperConnection Watcher:127.0.0.1:49087 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2395656 T8027 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2395656 T8027 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 2395657 T8027 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2395658 T8077 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f060521 name:ZooKeeperConnection Watcher:127.0.0.1:49087/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2395658 T8027 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2395661 T8027 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 2396664 T8027 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39565_ [junit4] 2> 2396665 T8027 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39565_ [junit4] 2> 2396669 T8027 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 2396674 T8079 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1 [junit4] 2> 2396674 T8079 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 2396676 T8054 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2396677 T8079 oasc.ZkController.preRegister Registering watch for external collection collection1 [junit4] 2> 2396677 T8079 oascc.ZkStateReader.addZkWatch addZkWatch collection1 [junit4] 2> 2396678 T8079 oascc.ZkStateReader.addZkWatch Updating collection state at /collections/collection1/state.json from ZooKeeper... [junit4] 2> 2396679 T8079 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 0 [junit4] 2> 2396680 T8050 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "core":"collection1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:39565";, [junit4] 2> "node_name":"127.0.0.1:39565_", [junit4] 2> "numShards":"1", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 2396680 T8079 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 2396685 T8050 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1 [junit4] 2> 2396686 T8050 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 2396693 T8050 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json [junit4] 2> 2396693 T8078 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 2396694 T8078 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 1 [junit4] 2> 2397680 T8079 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 2397681 T8079 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1 [junit4] 2> 2397681 T8079 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 2397681 T8079 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 2397682 T8079 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 2397682 T8079 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-003/collection1/' [junit4] 2> 2397683 T8079 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-003/collection1/lib/.svn/' to classloader [junit4] 2> 2397683 T8079 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-003/collection1/lib/classes/' to classloader [junit4] 2> 2397683 T8079 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-003/collection1/lib/README' to classloader [junit4] 2> 2397700 T8079 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0 [junit4] 2> 2397713 T8079 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 2397715 T8079 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml [junit4] 2> 2397718 T8079 oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 2397796 T8079 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 2397799 T8079 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 2397800 T8079 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 2397807 T8079 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 2397812 T8079 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 2397814 T8079 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 2397814 T8079 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 2397814 T8079 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 2397815 T8079 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 2397815 T8079 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 2397815 T8079 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 2397815 T8079 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 2397815 T8079 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 2397816 T8079 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-003/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-001/jetty1/ [junit4] 2> 2397816 T8079 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1c05a4fa [junit4] 2> 2397816 T8079 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-001/jetty1 [junit4] 2> 2397817 T8079 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-001/jetty1/index/ [junit4] 2> 2397817 T8079 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-001/jetty1/index' doesn't exist. Creating new index... [junit4] 2> 2397817 T8079 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-001/jetty1/index [junit4] 2> 2397817 T8079 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3323435406429077] [junit4] 2> 2397818 T8079 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-2a85ac56)),segFN=segments_1,generation=1} [junit4] 2> 2397818 T8079 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 2397820 T8079 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 2397821 T8079 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 2397821 T8079 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 2397821 T8079 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 2397821 T8079 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 2397821 T8079 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 2397822 T8079 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 2397822 T8079 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 2397822 T8079 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 2397823 T8079 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 2397823 T8079 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 2397823 T8079 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 2397824 T8079 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 2397824 T8079 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 2397824 T8079 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 2397824 T8079 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 2397825 T8079 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 2397825 T8079 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 2397825 T8079 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 2397826 T8079 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 2397827 T8079 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 2397828 T8079 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 2397829 T8079 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 2397829 T8079 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 2397831 T8079 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 2397831 T8079 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 2397831 T8079 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=25, maxMergedSegmentMB=31.357421875, floorSegmentMB=0.748046875, forceMergeDeletesPctAllowed=4.7190611138423835, segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2709423214829504 [junit4] 2> 2397832 T8079 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-2a85ac56)),segFN=segments_1,generation=1} [junit4] 2> 2397832 T8079 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 2397832 T8079 oass.SolrIndexSearcher.<init> Opening Searcher@72757396[collection1] main [junit4] 2> 2397832 T8079 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 2397833 T8079 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 2397833 T8079 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 2397834 T8079 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2397834 T8079 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 2397834 T8079 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2397834 T8079 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json [junit4] 2> 2397835 T8079 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2397835 T8079 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed [junit4] 2> 2397835 T8079 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 2397837 T8080 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@72757396[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2397837 T8079 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 2397838 T8083 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:39565 collection:collection1 shard:shard1 [junit4] 2> 2397838 T8027 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0 [junit4] 2> 2397839 T8027 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 2397839 T8083 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 2397841 T8083 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1 [junit4] 2> 2397842 T8054 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2397842 T8083 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue. [junit4] 2> 2397843 T8083 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync [junit4] 2> ASYNC NEW_CORE C5950 name=collection1 org.apache.solr.core.SolrCore@5dae7bde url=http://127.0.0.1:39565/collection1 node=127.0.0.1:39565_ C5950_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:39565, node_name=127.0.0.1:39565_, state=down} [junit4] 2> 2397843 T8083 C5950 P39565 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:39565/collection1/ [junit4] 2> 2397843 T8083 C5950 P39565 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me [junit4] 2> 2397843 T8083 C5950 P39565 oasc.SyncStrategy.syncToMe http://127.0.0.1:39565/collection1/ has no replicas [junit4] 2> 2397843 T8083 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:39565/collection1/ shard1 [junit4] 2> 2397843 T8083 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2397845 T8050 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json [junit4] 2> 2397846 T8078 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 2397846 T8078 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 2 [junit4] 2> 2397848 T8054 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2397848 T8050 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json [junit4] 2> 2397849 T8078 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 2397849 T8078 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 3 [junit4] 2> 2397896 T8083 oasc.ZkController.register We are http://127.0.0.1:39565/collection1/ and leader is http://127.0.0.1:39565/collection1/ [junit4] 2> 2397896 T8083 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39565 [junit4] 2> 2397897 T8083 oasc.ZkController.checkRecovery I am the leader, no recovery necessary [junit4] 2> 2397897 T8083 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1 [junit4] 2> 2397897 T8083 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 2397898 T8054 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2397899 T8083 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 3 [junit4] 2> 2397899 T8050 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "core":"collection1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:39565";, [junit4] 2> "node_name":"127.0.0.1:39565_", [junit4] 2> "numShards":"1", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 2397901 T8050 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json [junit4] 2> 2397902 T8078 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 2397902 T8078 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 4 [junit4] 2> 2398088 T8027 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2 [junit4] 2> 2398089 T8027 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 2398090 T8027 oejs.AbstractConnector.doStart Started [email protected]:55165 [junit4] 2> 2398091 T8027 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 2398092 T8027 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 2398092 T8027 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-004 [junit4] 2> 2398092 T8027 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-004/' [junit4] 2> 2398103 T8027 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-004/solr.xml [junit4] 2> 2398117 T8027 oasc.CoreContainer.<init> New CoreContainer 1129394466 [junit4] 2> 2398117 T8027 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-004/] [junit4] 2> 2398117 T8027 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 2398118 T8027 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 2398118 T8027 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 2398118 T8027 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 2398119 T8027 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 2398119 T8027 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 2398119 T8027 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 2398119 T8027 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 2398120 T8027 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 2398120 T8027 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 2398120 T8027 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 2398121 T8027 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 2398121 T8027 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 2398121 T8027 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49087/solr [junit4] 2> 2398121 T8027 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 2398122 T8027 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 2398123 T8027 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2398123 T8095 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b776a3e name:ZooKeeperConnection Watcher:127.0.0.1:49087 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2398124 T8027 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2398124 T8027 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 2398125 T8027 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2398126 T8097 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3eb7a5fd name:ZooKeeperConnection Watcher:127.0.0.1:49087/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2398126 T8027 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2398129 T8027 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 2399131 T8027 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42937_ [junit4] 2> 2399132 T8027 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42937_ [junit4] 2> 2399134 T8027 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 2399137 T8099 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1 [junit4] 2> 2399138 T8099 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 2399139 T8054 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2399140 T8099 oasc.ZkController.preRegister Registering watch for external collection collection1 [junit4] 2> 2399140 T8099 oascc.ZkStateReader.addZkWatch addZkWatch collection1 [junit4] 2> 2399140 T8099 oascc.ZkStateReader.addZkWatch Updating collection state at /collections/collection1/state.json from ZooKeeper... [junit4] 2> 2399141 T8099 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 4 [junit4] 2> 2399141 T8050 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "core":"collection1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:42937";, [junit4] 2> "node_name":"127.0.0.1:42937_", [junit4] 2> "numShards":"1", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 2399141 T8099 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 2399143 T8050 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1 [junit4] 2> 2399144 T8050 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 2399147 T8050 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json [junit4] 2> 2399148 T8078 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 2399148 T8098 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 2399148 T8078 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 5 [junit4] 2> 2399148 T8098 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 5 [junit4] 2> 2400142 T8099 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 2400142 T8099 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1 [junit4] 2> 2400143 T8099 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 2400143 T8099 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 2400143 T8099 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 2400143 T8099 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-004/collection1/' [junit4] 2> 2400144 T8099 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-004/collection1/lib/.svn/' to classloader [junit4] 2> 2400144 T8099 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-004/collection1/lib/classes/' to classloader [junit4] 2> 2400144 T8099 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-004/collection1/lib/README' to classloader [junit4] 2> 2400161 T8099 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0 [junit4] 2> 2400173 T8099 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 2400174 T8099 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml [junit4] 2> 2400177 T8099 oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 2400258 T8099 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 2400261 T8099 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 2400262 T8099 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 2400268 T8099 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 2400270 T8099 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 2400271 T8099 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 2400272 T8099 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 2400272 T8099 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 2400272 T8099 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 2400273 T8099 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 2400273 T8099 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 2400273 T8099 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 2400273 T8099 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 2400273 T8099 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-004/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-001/jetty2/ [junit4] 2> 2400273 T8099 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1c05a4fa [junit4] 2> 2400274 T8099 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-001/jetty2 [junit4] 2> 2400274 T8099 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-001/jetty2/index/ [junit4] 2> 2400274 T8099 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-001/jetty2/index' doesn't exist. Creating new index... [junit4] 2> 2400274 T8099 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-001/jetty2/index [junit4] 2> 2400275 T8099 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3323435406429077] [junit4] 2> 2400275 T8099 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-506395d2)),segFN=segments_1,generation=1} [junit4] 2> 2400275 T8099 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 2400277 T8099 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 2400277 T8099 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 2400278 T8099 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 2400278 T8099 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 2400278 T8099 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 2400278 T8099 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 2400278 T8099 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 2400279 T8099 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 2400279 T8099 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 2400279 T8099 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 2400279 T8099 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 2400280 T8099 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 2400286 T8099 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 2400286 T8099 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 2400287 T8099 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 2400287 T8099 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 2400287 T8099 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 2400287 T8099 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 2400288 T8099 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 2400288 T8099 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 2400289 T8099 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 2400290 T8099 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 2400291 T8099 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 2400291 T8099 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 2400292 T8099 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 2400293 T8099 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 2400293 T8099 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=25, maxMergedSegmentMB=31.357421875, floorSegmentMB=0.748046875, forceMergeDeletesPctAllowed=4.7190611138423835, segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2709423214829504 [junit4] 2> 2400293 T8099 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-506395d2)),segFN=segments_1,generation=1} [junit4] 2> 2400293 T8099 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 2400294 T8099 oass.SolrIndexSearcher.<init> Opening Searcher@58c2b989[collection1] main [junit4] 2> 2400294 T8099 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 2400295 T8099 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 2400295 T8099 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 2400295 T8099 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2400295 T8099 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 2400296 T8099 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2400297 T8099 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json [junit4] 2> 2400297 T8099 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2400297 T8099 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed [junit4] 2> 2400297 T8099 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 2400300 T8100 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@58c2b989[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2400301 T8099 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 2400302 T8103 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42937 collection:collection1 shard:shard1 [junit4] 2> 2400302 T8027 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0 [junit4] 2> 2400302 T8027 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 2400303 T8103 oasc.ZkController.register We are http://127.0.0.1:42937/collection1/ and leader is http://127.0.0.1:39565/collection1/ [junit4] 2> 2400303 T8103 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42937 [junit4] 2> 2400304 T8103 oasc.ZkController.checkRecovery Core needs to recover:collection1 [junit4] 2> 2400304 T8103 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery [junit4] 2> ASYNC NEW_CORE C5951 name=collection1 org.apache.solr.core.SolrCore@5b378119 url=http://127.0.0.1:42937/collection1 node=127.0.0.1:42937_ C5951_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:42937, node_name=127.0.0.1:42937_, state=down} [junit4] 2> 2400304 T8105 C5951 P42937 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true [junit4] 2> 2400305 T8105 C5951 P42937 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[] [junit4] 2> 2400305 T8105 C5951 P42937 oasc.RecoveryStrategy.doRecovery Publishing state of core collection1 as recovering, leader is http://127.0.0.1:39565/collection1/ and I am http://127.0.0.1:42937/collection1/ [junit4] 2> 2400305 T8105 C5951 P42937 oasc.ZkController.publish publishing core=collection1 state=recovering collection=collection1 [junit4] 2> 2400305 T8105 C5951 P42937 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 2400306 T8054 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2400306 T8103 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 5 [junit4] 2> 2400306 T8105 C5951 P42937 oasc.RecoveryStrategy.sendPrepRecoveryCmd Sending prep recovery command to http://127.0.0.1:39565; WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1%3A42937_&coreNodeName=core_node2&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true [junit4] 2> 2400307 T8084 oasc.SocketProxy$Acceptor.run accepted Socket[addr=/127.0.0.1,port=55502,localport=39565], receiveBufferSize:531000 [junit4] 2> 2400307 T8084 oasc.SocketProxy$Bridge.<init> proxy connection Socket[addr=/127.0.0.1,port=48512,localport=34790], receiveBufferSize=530904 [junit4] 2> 2400308 T8071 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true [junit4] 2> 2400308 T8050 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "core":"collection1", [junit4] 2> "core_node_name":"core_node2", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:42937";, [junit4] 2> "node_name":"127.0.0.1:42937_", [junit4] 2> "numShards":"1", [junit4] 2> "state":"recovering", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 2400310 T8071 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 5 [junit4] 2> 2400310 T8071 oasha.CoreAdminHandler.handleWaitForStateAction Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering [junit4] 2> 2400310 T8071 oasha.CoreAdminHandler.handleWaitForStateAction In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:42937_, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"core":"collection1","base_url":"http://127.0.0.1:42937","node_name":"127.0.0.1:42937_","state":"down"} [junit4] 2> 2400311 T8050 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json [junit4] 2> 2400311 T8078 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 2400311 T8098 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 2400312 T8078 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 6 [junit4] 2> 2400312 T8098 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 6 [junit4] 2> 2400551 T8027 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3 [junit4] 2> 2400552 T8027 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 2400554 T8027 oejs.AbstractConnector.doStart Started [email protected]:54440 [junit4] 2> 2400554 T8027 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 2400555 T8027 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 2400555 T8027 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-005 [junit4] 2> 2400555 T8027 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-005/' [junit4] 2> 2400565 T8027 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tempDir-005/solr.xml [junit4] 2> 2400581 T8027 oasc.CoreContainer.<init> New CoreContainer 546549148 [junit4] 2> 2400581 T8027 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001/tem [...truncated too long message...] > 2446522 T8027 oasc.SocketProxy.close WARN Closing 0 connections to: > http://127.0.0.1:39565/ [junit4] 2> 2446522 T8027 oasc.SocketProxy.close WARN Closing 0 connections to: http://127.0.0.1:39371/ [junit4] 2> 2446523 T8027 oasc.SocketProxy.close WARN Closing 0 connections to: http://127.0.0.1:52495/ [junit4] 2> 2446523 T8027 oasc.SocketProxy.close WARN Closing 0 connections to: http://127.0.0.1:37001/ [junit4] 2> 2446523 T8027 oasc.SocketProxy.close WARN Closing 0 connections to: http://127.0.0.1:42937/ [junit4] 2> 2446524 T8027 oasc.SocketProxy.close WARN Closing 0 connections to: http://127.0.0.1:39565/ [junit4] 2> 2446524 T8027 oasc.SocketProxy.close WARN Closing 0 connections to: http://127.0.0.1:39371/ [junit4] 2> 2446524 T8027 oasc.SocketProxy.close WARN Closing 0 connections to: http://127.0.0.1:52495/ [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=LeaderInitiatedRecoveryOnCommitTest -Dtests.method=testDistribSearch -Dtests.seed=3C3623CE94700F57 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=bg_BG -Dtests.timezone=Europe/Dublin -Dtests.file.encoding=US-ASCII [junit4] ERROR 52.8s J0 | LeaderInitiatedRecoveryOnCommitTest.testDistribSearch <<< [junit4] > Throwable #1: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: http://127.0.0.1:39565 [junit4] > at __randomizedtesting.SeedInfo.seed([3C3623CE94700F57:BDD0ADD6E32F6F6B]:0) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:578) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:215) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:211) [junit4] > at org.apache.solr.cloud.BasicDistributedZkTest.createCollection(BasicDistributedZkTest.java:612) [junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1579) [junit4] > at org.apache.solr.cloud.LeaderInitiatedRecoveryOnCommitTest.multiShardTest(LeaderInitiatedRecoveryOnCommitTest.java:77) [junit4] > at org.apache.solr.cloud.LeaderInitiatedRecoveryOnCommitTest.doTest(LeaderInitiatedRecoveryOnCommitTest.java:71) [junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869) [junit4] > at java.lang.Thread.run(Thread.java:745) [junit4] > Caused by: java.net.ConnectException: Connection refused [junit4] > at java.net.PlainSocketImpl.socketConnect(Native Method) [junit4] > at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:345) [junit4] > at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) [junit4] > at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) [junit4] > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) [junit4] > at java.net.Socket.connect(Socket.java:589) [junit4] > at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:117) [junit4] > at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:178) [junit4] > at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:304) [junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:610) [junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:445) [junit4] > at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:863) [junit4] > at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) [junit4] > at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106) [junit4] > at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:466) [junit4] > ... 47 more [junit4] 2> 2446541 T8027 oas.SolrTestCaseJ4.deleteCore ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderInitiatedRecoveryOnCommitTest-3C3623CE94700F57-001 [junit4] 2> NOTE: test params are: codec=Asserting(Lucene50): {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=bg_BG, timezone=Europe/Dublin [junit4] 2> NOTE: Linux 3.13.0-36-generic amd64/Oracle Corporation 1.8.0_40-ea (64-bit)/cpus=8,threads=1,free=132235440,total=329080832 [junit4] 2> NOTE: All tests run in this JVM: [SolrCoreCheckLockOnStartupTest, PreAnalyzedUpdateProcessorTest, ExternalFileFieldSortTest, StatelessScriptUpdateProcessorFactoryTest, TestStressReorder, TestCoreDiscovery, XsltUpdateRequestHandlerTest, TestSchemaVersionResource, TestArbitraryIndexDir, TestWordDelimiterFilterFactory, TestRTGBase, DisMaxRequestHandlerTest, SolrIndexSplitterTest, TestHashPartitioner, ShardSplitTest, TestSchemaResource, HdfsDirectoryTest, TestBulkSchemaAPI, TestRawResponseWriter, TestMissingGroups, IndexBasedSpellCheckerTest, CurrencyFieldOpenExchangeTest, ModifyConfFileTest, XmlUpdateRequestHandlerTest, TestFuzzyAnalyzedSuggestions, TestNonDefinedSimilarityFactory, TestDFRSimilarityFactory, SpellPossibilityIteratorTest, TestCustomSort, AtomicUpdatesTest, TestOrdValues, DocumentAnalysisRequestHandlerTest, TestFreeTextSuggestions, HdfsSyncSliceTest, ZkControllerTest, BasicDistributedZkTest, DistributedQueryComponentCustomSortTest, DistributedSpellCheckComponentTest, MultiThreadedOCPTest, ResponseLogComponentTest, SuggesterTest, MigrateRouteKeyTest, StandardRequestHandlerTest, HdfsWriteToMultipleCollectionsTest, TestConfigSets, TestSearcherReuse, TestManagedStopFilterFactory, TestNRTOpen, ZkNodePropsTest, TestSolrIndexConfig, TestStressRecovery, TestLRUCache, TestCursorMarkWithoutUniqueKey, MinimalSchemaTest, ExternalCollectionsTest, TestFastOutputStream, DirectUpdateHandlerTest, HighlighterConfigTest, TestComplexPhraseQParserPlugin, OverseerRolesTest, BlockCacheTest, CloudExitableDirectoryReaderTest, TestSuggestSpellingConverter, TestCloudPivotFacet, TestExceedMaxTermLength, ShowFileRequestHandlerTest, NoCacheHeaderTest, TestCodecSupport, TestFoldingMultitermQuery, PrimitiveFieldTypeTest, OverseerTest, TestSort, EnumFieldTest, ReturnFieldsTest, DistributedDebugComponentTest, TestCollapseQParserPlugin, TestSolrDeletionPolicy1, HttpPartitionTest, TestRangeQuery, TestLMDirichletSimilarityFactory, TestComponentsName, TestTrie, TestAnalyzedSuggestions, LeaderElectionTest, TestCloudManagedSchemaConcurrent, HdfsBasicDistributedZk2Test, TestSolrJ, NotRequiredUniqueKeyTest, DocumentBuilderTest, RegexBoostProcessorTest, RemoteQueryErrorTest, FileUtilsTest, JsonLoaderTest, AsyncMigrateRouteKeyTest, TestFaceting, TestNonNRTOpen, ClusterStateUpdateTest, TestIntervalFaceting, AnalysisErrorHandlingTest, BadIndexSchemaTest, RequiredFieldsTest, TestSchemaSimilarityResource, TestFastWriter, RankQueryTest, DocValuesMultiTest, TestLuceneMatchVersion, TestReplicationHandler, TestStressVersions, TestCoreContainer, SimpleFacetsTest, TestSolr4Spatial, StatsComponentTest, SpellCheckComponentTest, SolrCmdDistributorTest, BasicFunctionalityTest, TestLazyCores, DistributedQueryElevationComponentTest, TestUpdate, FieldMutatingUpdateProcessorTest, TestRemoteStreaming, TermVectorComponentTest, MoreLikeThisHandlerTest, FastVectorHighlighterTest, TestJmxIntegration, JSONWriterTest, TestPartialUpdateDeduplication, SearchHandlerTest, UpdateParamsTest, BadComponentTest, TestDocSet, NumericFieldsTest, TestPhraseSuggestions, TestCharFilters, SynonymTokenizerTest, TestXIncludeConfig, EchoParamsTest, TestSweetSpotSimilarityFactory, TestPerFieldSimilarity, TestLMJelinekMercerSimilarityFactory, TestIBSimilarityFactory, TestBM25SimilarityFactory, TestDefaultSimilarityFactory, LegacyHTMLStripCharFilterTest, TestJmxMonitoredMap, TimeZoneUtilsTest, ResourceLoaderTest, OpenExchangeRatesOrgProviderTest, PluginInfoTest, TestFastLRUCache, ChaosMonkeyNothingIsSafeTest, AssignTest, CollectionsAPIAsyncDistributedZkTest, DeleteReplicaTest, DeleteShardTest, DistribDocExpirationUpdateProcessorTest, LeaderInitiatedRecoveryOnCommitTest] [junit4] Completed on J0 in 52.88s, 1 test, 1 error <<< FAILURES! [...truncated 253 lines...] BUILD FAILED /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:524: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:472: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:61: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:39: 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:496: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1359: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:961: There were test failures: 436 suites, 1783 tests, 1 error, 44 ignored (22 assumptions) Total time: 91 minutes 9 seconds Build step 'Invoke Ant' marked build as failure [description-setter] Description set: Java: 64bit/jdk1.8.0_40-ea-b04 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC Archiving artifacts Recording test results Email was triggered for: Failure - Any Sending email for trigger: Failure - Any
--------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
