Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/4390/ Java: 64bit/jdk1.7.0_67 -XX:-UseCompressedOops -XX:+UseG1GC
1 tests failed. REGRESSION: org.apache.solr.cloud.BasicDistributedZkTest.testDistribSearch Error Message: commitWithin did not work on node: http://127.0.0.1:55877/vhml/n/collection1 expected:<68> but was:<67> Stack Trace: java.lang.AssertionError: commitWithin did not work on node: http://127.0.0.1:55877/vhml/n/collection1 expected:<68> but was:<67> at __randomizedtesting.SeedInfo.seed([EE62A9CE06EE40E4:6F8427D671B120D8]:0) at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.failNotEquals(Assert.java:647) at org.junit.Assert.assertEquals(Assert.java:128) at org.junit.Assert.assertEquals(Assert.java:472) at org.apache.solr.cloud.BasicDistributedZkTest.doTest(BasicDistributedZkTest.java:345) at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869) at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50) at org.apache.lucene.util.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:54) 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) Build Log: [...truncated 11136 lines...] [junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest [junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\init-core-data-001 [junit4] 2> 4375733 T10163 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /vhml/n [junit4] 2> 4375740 T10163 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch [junit4] 2> 4375743 T10163 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 4375744 T10164 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 4375862 T10163 oasc.ZkTestServer.run start zk server on port:55858 [junit4] 2> 4375863 T10163 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 4375864 T10163 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 4375872 T10170 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26d5da45 name:ZooKeeperConnection Watcher:127.0.0.1:55858 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 4375873 T10163 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 4375875 T10163 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 4375875 T10163 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 4375887 T10163 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 4375891 T10163 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 4375893 T10172 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@43a28d7e name:ZooKeeperConnection Watcher:127.0.0.1:55858/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 4375893 T10163 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 4375893 T10163 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 4375893 T10163 oascc.SolrZkClient.makePath makePath: /collections/collection1 [junit4] 2> 4375900 T10163 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards [junit4] 2> 4375906 T10163 oascc.SolrZkClient.makePath makePath: /collections/control_collection [junit4] 2> 4375911 T10163 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards [junit4] 2> 4375916 T10163 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4] 2> 4375918 T10163 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml [junit4] 2> 4375924 T10163 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml [junit4] 2> 4375926 T10163 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml [junit4] 2> 4375933 T10163 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 4375933 T10163 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 4375938 T10163 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt [junit4] 2> 4375940 T10163 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt [junit4] 2> 4375945 T10163 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt [junit4] 2> 4375946 T10163 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt [junit4] 2> 4375951 T10163 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml [junit4] 2> 4375952 T10163 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml [junit4] 2> 4375957 T10163 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\enumsConfig.xml to /configs/conf1/enumsConfig.xml [junit4] 2> 4375958 T10163 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml [junit4] 2> 4375964 T10163 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json [junit4] 2> 4375965 T10163 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json [junit4] 2> 4375971 T10163 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 4375972 T10163 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 4375978 T10163 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4] 2> 4375978 T10163 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt [junit4] 2> 4375986 T10163 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt [junit4] 2> 4375987 T10163 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt [junit4] 2> 4377898 T10163 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 4377962 T10163 oejs.AbstractConnector.doStart Started [email protected]:55865 [junit4] 2> 4377962 T10163 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 4377962 T10163 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 4377962 T10163 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-002 [junit4] 2> 4377965 T10163 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-002\' [junit4] 2> 4378013 T10163 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-002\solr.xml [junit4] 2> 4378110 T10163 oasc.CoreContainer.<init> New CoreContainer 213545481 [junit4] 2> 4378111 T10163 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-002\] [junit4] 2> 4378112 T10163 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 4378112 T10163 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 4378113 T10163 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 4378113 T10163 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 4378113 T10163 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000 [junit4] 2> 4378114 T10163 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 4378114 T10163 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 4378114 T10163 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 4378114 T10163 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 4378116 T10163 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 4378116 T10163 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 4378117 T10163 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 4378117 T10163 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 4378117 T10163 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 4378118 T10163 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55858/solr [junit4] 2> 4378118 T10163 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 4378118 T10163 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 4378121 T10163 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 4378124 T10183 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2494b366 name:ZooKeeperConnection Watcher:127.0.0.1:55858 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 4378125 T10163 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 4378125 T10163 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 4378129 T10165 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x149460d68590002, likely client has closed socket [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228) [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> [junit4] 2> 4378132 T10163 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 4378134 T10185 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6861609 name:ZooKeeperConnection Watcher:127.0.0.1:55858/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 4378134 T10163 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 4378139 T10163 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 4378146 T10163 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 4378153 T10163 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 4378158 T10163 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 4378164 T10163 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 4378170 T10163 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 4378173 T10163 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55865_vhml%2Fn [junit4] 2> 4378176 T10163 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55865_vhml%2Fn [junit4] 2> 4378182 T10163 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 4378187 T10163 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 4378191 T10163 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 4378195 T10163 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55865_vhml%2Fn [junit4] 2> 4378195 T10163 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 4378199 T10163 oasc.Overseer.start Overseer (id=92682290736988163-127.0.0.1:55865_vhml%2Fn-n_0000000000) starting [junit4] 2> 4378205 T10163 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 4378226 T10163 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 4378227 T10187 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 4378230 T10163 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 4378235 T10163 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 4378238 T10163 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 4378245 T10186 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 4378258 T10189 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection [junit4] 2> 4378258 T10189 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 4378261 T10189 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 4378263 T10190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4378274 T10186 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "roles":null, [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"control_collection", [junit4] 2> "base_url":"http://127.0.0.1:55865/vhml/n";, [junit4] 2> "numShards":"1", [junit4] 2> "node_name":"127.0.0.1:55865_vhml%2Fn", [junit4] 2> "core":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 4378274 T10186 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1] [junit4] 2> 4378275 T10186 oasc.Overseer$ClusterStateUpdater.createCollection state version control_collection 1 [junit4] 2> 4378275 T10186 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 4378282 T10190 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> 4379447 T10189 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 4379447 T10189 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection [junit4] 2> 4379449 T10189 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 4379449 T10189 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection [junit4] 2> 4379451 T10189 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper [junit4] 2> 4379452 T10189 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-002\collection1\' [junit4] 2> 4379460 T10189 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001/tempDir-002/collection1/lib/.svn/' to classloader [junit4] 2> 4379462 T10189 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001/tempDir-002/collection1/lib/classes/' to classloader [junit4] 2> 4379466 T10189 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001/tempDir-002/collection1/lib/README' to classloader [junit4] 2> 4379621 T10189 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0 [junit4] 2> 4379680 T10189 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 4379684 T10189 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml [junit4] 2> 4379698 T10189 oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 4380190 T10189 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 4380201 T10189 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 4380206 T10189 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 4380227 T10189 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 4380233 T10189 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 4380240 T10189 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 4380242 T10189 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 4380243 T10189 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 4380243 T10189 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 4380245 T10189 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 4380245 T10189 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 4380245 T10189 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection [junit4] 2> 4380245 T10189 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 4380246 T10189 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-002\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-001/control/data\ [junit4] 2> 4380246 T10189 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@492aa0bf [junit4] 2> 4380248 T10189 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-001/control/data\ [junit4] 2> 4380248 T10189 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-001/control/data\index/ [junit4] 2> 4380248 T10189 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-001\control\data\index' doesn't exist. Creating new index... [junit4] 2> 4380249 T10189 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-001/control/data\index [junit4] 2> 4380249 T10189 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=26, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0] [junit4] 2> 4380250 T10189 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-38528013)),segFN=segments_1,generation=1} [junit4] 2> 4380250 T10189 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 4380255 T10189 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 4380256 T10189 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 4380256 T10189 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 4380256 T10189 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 4380257 T10189 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 4380257 T10189 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 4380258 T10189 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 4380258 T10189 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 4380258 T10189 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 4380259 T10189 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 4380259 T10189 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 4380260 T10189 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 4380260 T10189 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 4380262 T10189 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 4380262 T10189 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 4380262 T10189 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 4380263 T10189 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 4380263 T10189 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 4380264 T10189 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 4380264 T10189 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 4380278 T10189 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4380280 T10189 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4380284 T10189 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4380286 T10189 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4380292 T10189 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 4380293 T10189 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 4380293 T10189 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=45, maxMergeAtOnceExplicit=49, maxMergedSegmentMB=68.671875, floorSegmentMB=1.2470703125, forceMergeDeletesPctAllowed=9.543528728713706, segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0 [junit4] 2> 4380294 T10189 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-38528013)),segFN=segments_1,generation=1} [junit4] 2> 4380294 T10189 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 4380294 T10189 oass.SolrIndexSearcher.<init> Opening Searcher@3c7a6d69[collection1] main [junit4] 2> 4380294 T10189 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection [junit4] 2> 4380296 T10189 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper [junit4] 2> 4380297 T10189 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 4380297 T10189 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 4380299 T10189 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 4380299 T10189 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 4380300 T10189 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json [junit4] 2> 4380300 T10189 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 4380301 T10189 oascc.SolrZkClient.makePath makePath: /configs/conf1/_rest_managed.json [junit4] 2> 4380306 T10189 oasr.ManagedResourceStorage$ZooKeeperStorageIO$1.close Wrote 38 bytes to new znode /configs/conf1/_rest_managed.json [junit4] 2> 4380306 T10189 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 4380306 T10189 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 4380309 T10191 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3c7a6d69[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 4380311 T10189 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 4380312 T10194 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55865/vhml/n collection:control_collection shard:shard1 [junit4] 2> 4380314 T10163 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0 [junit4] 2> 4380314 T10163 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 4380315 T10163 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 4380316 T10194 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election [junit4] 2> 4380318 T10163 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 4380321 T10196 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7690c362 name:ZooKeeperConnection Watcher:127.0.0.1:55858/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 4380322 T10163 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 4380322 T10163 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 4380325 T10163 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 4380328 T10194 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1 [junit4] 2> 4380331 T10190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4380332 T10163 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false [junit4] 2> 4380332 T10194 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue. [junit4] 2> 4380332 T10194 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync [junit4] 2> ASYNC NEW_CORE C2649 name=collection1 org.apache.solr.core.SolrCore@33d87591 url=http://127.0.0.1:55865/vhml/n/collection1 node=127.0.0.1:55865_vhml%2Fn C2649_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:55865/vhml/n, node_name=127.0.0.1:55865_vhml%2Fn, core=collection1} [junit4] 2> 4380332 T10194 C2649 P55865 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55865/vhml/n/collection1/ [junit4] 2> 4380333 T10194 C2649 P55865 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me [junit4] 2> 4380333 T10194 C2649 P55865 oasc.SyncStrategy.syncToMe http://127.0.0.1:55865/vhml/n/collection1/ has no replicas [junit4] 2> 4380333 T10194 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55865/vhml/n/collection1/ shard1 [junit4] 2> 4380333 T10194 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1 [junit4] 2> 4380353 T10190 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> 4380355 T10197 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> 4380375 T10190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4380377 T10190 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> 4380377 T10197 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> 4380412 T10194 oasc.ZkController.register We are http://127.0.0.1:55865/vhml/n/collection1/ and leader is http://127.0.0.1:55865/vhml/n/collection1/ [junit4] 2> 4380412 T10194 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55865/vhml/n [junit4] 2> 4380412 T10194 oasc.ZkController.checkRecovery I am the leader, no recovery necessary [junit4] 2> 4380412 T10194 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection [junit4] 2> 4380412 T10194 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 4380414 T10190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4380436 T10186 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "roles":null, [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"control_collection", [junit4] 2> "base_url":"http://127.0.0.1:55865/vhml/n";, [junit4] 2> "numShards":"2", [junit4] 2> "node_name":"127.0.0.1:55865_vhml%2Fn", [junit4] 2> "core":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 4380563 T10190 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> 4380563 T10197 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> 4382326 T10163 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1 [junit4] 2> 4382327 T10163 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 4382330 T10163 oejs.AbstractConnector.doStart Started [email protected]:55877 [junit4] 2> 4382332 T10163 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 4382332 T10163 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 4382332 T10163 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-003 [junit4] 2> 4382332 T10163 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-003\' [junit4] 2> 4382373 T10163 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-003\solr.xml [junit4] 2> 4382444 T10163 oasc.CoreContainer.<init> New CoreContainer 1328222011 [junit4] 2> 4382444 T10163 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-003\] [junit4] 2> 4382446 T10163 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 4382446 T10163 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 4382446 T10163 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 4382446 T10163 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 4382446 T10163 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000 [junit4] 2> 4382446 T10163 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 4382446 T10163 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 4382446 T10163 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 4382446 T10163 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 4382446 T10163 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 4382449 T10163 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 4382449 T10163 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 4382449 T10163 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 4382449 T10163 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 4382449 T10163 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55858/solr [junit4] 2> 4382449 T10163 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 4382451 T10163 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 4382453 T10163 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 4382455 T10208 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13f51318 name:ZooKeeperConnection Watcher:127.0.0.1:55858 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 4382456 T10163 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 4382456 T10163 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 4382461 T10163 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 4382462 T10210 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@74fbfabc name:ZooKeeperConnection Watcher:127.0.0.1:55858/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 4382463 T10163 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 4382473 T10163 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 4383549 T10163 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55877_vhml%2Fn [junit4] 2> 4383552 T10163 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55877_vhml%2Fn [junit4] 2> 4383568 T10163 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 4383582 T10212 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1 [junit4] 2> 4383583 T10212 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 4383585 T10190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4383585 T10212 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 4383594 T10186 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "roles":null, [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://127.0.0.1:55877/vhml/n";, [junit4] 2> "numShards":"2", [junit4] 2> "node_name":"127.0.0.1:55877_vhml%2Fn", [junit4] 2> "core":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 4383595 T10186 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2] [junit4] 2> 4383595 T10186 oasc.Overseer$ClusterStateUpdater.createCollection state version collection1 1 [junit4] 2> 4383595 T10186 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2 [junit4] 2> 4383602 T10197 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2) [junit4] 2> 4383602 T10211 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2) [junit4] 2> 4383603 T10190 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2) [junit4] 2> 4384654 T10212 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 4384654 T10212 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1 [junit4] 2> 4384656 T10212 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 4384657 T10212 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 4384661 T10212 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 4384662 T10212 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-003\collection1\' [junit4] 2> 4384669 T10212 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001/tempDir-003/collection1/lib/.svn/' to classloader [junit4] 2> 4384673 T10212 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001/tempDir-003/collection1/lib/classes/' to classloader [junit4] 2> 4384674 T10212 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001/tempDir-003/collection1/lib/README' to classloader [junit4] 2> 4384747 T10212 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0 [junit4] 2> 4384801 T10212 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 4384804 T10212 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml [junit4] 2> 4384814 T10212 oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 4385317 T10212 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 4385326 T10212 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 4385329 T10212 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 4385349 T10212 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 4385355 T10212 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 4385361 T10212 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 4385364 T10212 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 4385365 T10212 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 4385365 T10212 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 4385367 T10212 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 4385367 T10212 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 4385367 T10212 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 4385368 T10212 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 4385368 T10212 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-003\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-001/jetty1\ [junit4] 2> 4385369 T10212 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@492aa0bf [junit4] 2> 4385369 T10212 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-001/jetty1\ [junit4] 2> 4385370 T10212 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-001/jetty1\index/ [junit4] 2> 4385370 T10212 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-001\jetty1\index' doesn't exist. Creating new index... [junit4] 2> 4385370 T10212 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-001/jetty1\index [junit4] 2> 4385371 T10212 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=26, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0] [junit4] 2> 4385372 T10212 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-4abb347b)),segFN=segments_1,generation=1} [junit4] 2> 4385372 T10212 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 4385377 T10212 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 4385377 T10212 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 4385377 T10212 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 4385378 T10212 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 4385378 T10212 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 4385378 T10212 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 4385379 T10212 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 4385379 T10212 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 4385379 T10212 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 4385380 T10212 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 4385381 T10212 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 4385381 T10212 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 4385382 T10212 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 4385382 T10212 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 4385383 T10212 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 4385383 T10212 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 4385384 T10212 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 4385384 T10212 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 4385385 T10212 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 4385385 T10212 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 4385396 T10212 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4385398 T10212 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4385400 T10212 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4385402 T10212 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4385407 T10212 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 4385407 T10212 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 4385408 T10212 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=45, maxMergeAtOnceExplicit=49, maxMergedSegmentMB=68.671875, floorSegmentMB=1.2470703125, forceMergeDeletesPctAllowed=9.543528728713706, segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0 [junit4] 2> 4385409 T10212 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-4abb347b)),segFN=segments_1,generation=1} [junit4] 2> 4385409 T10212 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 4385409 T10212 oass.SolrIndexSearcher.<init> Opening Searcher@e50f253[collection1] main [junit4] 2> 4385409 T10212 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 4385413 T10212 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 4385413 T10212 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 4385414 T10212 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 4385414 T10212 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 4385415 T10212 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 4385418 T10212 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json [junit4] 2> 4385418 T10212 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 4385418 T10212 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed [junit4] 2> 4385419 T10212 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 4385422 T10213 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e50f253[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 4385426 T10212 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 4385431 T10216 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55877/vhml/n collection:collection1 shard:shard2 [junit4] 2> 4385432 T10163 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0 [junit4] 2> 4385432 T10163 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 4385433 T10216 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election [junit4] 2> 4385445 T10216 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2 [junit4] 2> 4385448 T10190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4385449 T10216 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue. [junit4] 2> 4385449 T10216 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync [junit4] 2> ASYNC NEW_CORE C2650 name=collection1 org.apache.solr.core.SolrCore@7ebd48da url=http://127.0.0.1:55877/vhml/n/collection1 node=127.0.0.1:55877_vhml%2Fn C2650_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:55877/vhml/n, node_name=127.0.0.1:55877_vhml%2Fn, core=collection1} [junit4] 2> 4385450 T10216 C2650 P55877 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55877/vhml/n/collection1/ [junit4] 2> 4385450 T10216 C2650 P55877 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me [junit4] 2> 4385450 T10216 C2650 P55877 oasc.SyncStrategy.syncToMe http://127.0.0.1:55877/vhml/n/collection1/ has no replicas [junit4] 2> 4385450 T10216 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55877/vhml/n/collection1/ shard2 [junit4] 2> 4385452 T10216 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2 [junit4] 2> 4385480 T10190 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2) [junit4] 2> 4385480 T10211 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2) [junit4] 2> 4385481 T10197 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2) [junit4] 2> 4385499 T10190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4385502 T10190 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2) [junit4] 2> 4385502 T10211 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2) [junit4] 2> 4385503 T10197 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2) [junit4] 2> 4385537 T10216 oasc.ZkController.register We are http://127.0.0.1:55877/vhml/n/collection1/ and leader is http://127.0.0.1:55877/vhml/n/collection1/ [junit4] 2> 4385537 T10216 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55877/vhml/n [junit4] 2> 4385537 T10216 oasc.ZkController.checkRecovery I am the leader, no recovery necessary [junit4] 2> 4385537 T10216 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1 [junit4] 2> 4385537 T10216 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 4385539 T10190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4385546 T10186 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "roles":null, [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard2", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://127.0.0.1:55877/vhml/n";, [junit4] 2> "numShards":"2", [junit4] 2> "node_name":"127.0.0.1:55877_vhml%2Fn", [junit4] 2> "core":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 4385659 T10211 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2) [junit4] 2> 4385660 T10197 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2) [junit4] 2> 4385661 T10190 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2) [junit4] 2> 4387201 T10163 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2 [junit4] 2> 4387201 T10163 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 4387205 T10163 oejs.AbstractConnector.doStart Started [email protected]:55886 [junit4] 2> 4387211 T10163 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 4387211 T10163 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 4387211 T10163 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-004 [junit4] 2> 4387211 T10163 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-004\' [junit4] 2> 4387250 T10163 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-004\solr.xml [junit4] 2> 4387317 T10163 oasc.CoreContainer.<init> New CoreContainer 820351921 [junit4] 2> 4387317 T10163 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-004\] [junit4] 2> 4387319 T10163 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 4387319 T10163 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 4387319 T10163 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 4387319 T10163 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 4387319 T10163 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000 [junit4] 2> 4387319 T10163 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 4387319 T10163 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 4387321 T10163 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 4387321 T10163 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 4387321 T10163 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 4387321 T10163 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 4387321 T10163 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 4387321 T10163 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 4387324 T10163 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 4387324 T10163 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55858/solr [junit4] 2> 4387324 T10163 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 4387324 T10163 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 4387326 T10163 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 4387327 T10227 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3043628b name:ZooKeeperConnection Watcher:127.0.0.1:55858 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 4387329 T10163 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 4387329 T10163 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 4387332 T10163 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 4387335 T10229 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5d744755 name:ZooKeeperConnection Watcher:127.0.0.1:55858/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 4387335 T10163 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 4387345 T10163 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 4388419 T10163 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55886_vhml%2Fn [junit4] 2> 4388423 T10163 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55886_vhml%2Fn [junit4] 2> 4388438 T10163 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 4388452 T10231 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1 [junit4] 2> 4388452 T10231 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 4388455 T10190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4388455 T10231 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 4388462 T10186 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "roles":null, [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://127.0.0.1:55886/vhml/n";, [junit4] 2> "numShards":"2", [junit4] 2> "node_name":"127.0.0.1:55886_vhml%2Fn", [junit4] 2> "core":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 4388463 T10186 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2 [junit4] 2> 4388463 T10186 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 4388471 T10190 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 4388471 T10230 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 4388471 T10211 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 4388471 T10197 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 4389522 T10231 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 4389522 T10231 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1 [junit4] 2> 4389524 T10231 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 4389524 T10231 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 4389530 T10231 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 4389530 T10231 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-004\collection1\' [junit4] 2> 4389531 T10231 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001/tempDir-004/collection1/lib/.svn/' to classloader [junit4] 2> 4389534 T10231 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001/tempDir-004/collection1/lib/classes/' to classloader [junit4] 2> 4389537 T10231 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001/tempDir-004/collection1/lib/README' to classloader [junit4] 2> 4389612 T10231 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0 [junit4] 2> 4389668 T10231 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 4389671 T10231 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml [junit4] 2> 4389686 T10231 oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 4390136 T10231 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 4390148 T10231 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 4390151 T10231 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 4390173 T10231 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 4390178 T10231 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 4390184 T10231 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 4390185 T10231 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 4390187 T10231 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 4390188 T10231 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 4390192 T10231 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 4390192 T10231 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 4390192 T10231 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 4390193 T10231 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 4390193 T10231 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-004\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-001/jetty2\ [junit4] 2> 4390193 T10231 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@492aa0bf [junit4] 2> 4390194 T10231 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-001/jetty2\ [junit4] 2> 4390194 T10231 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-001/jetty2\index/ [junit4] 2> 4390195 T10231 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-001\jetty2\index' doesn't exist. Creating new index... [junit4] 2> 4390195 T10231 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-001/jetty2\index [junit4] 2> 4390196 T10231 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=26, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0] [junit4] 2> 4390196 T10231 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-3f160ab0)),segFN=segments_1,generation=1} [junit4] 2> 4390197 T10231 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 4390202 T10231 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 4390202 T10231 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 4390203 T10231 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 4390203 T10231 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 4390203 T10231 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 4390203 T10231 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 4390204 T10231 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 4390204 T10231 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 4390205 T10231 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 4390206 T10231 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 4390207 T10231 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 4390207 T10231 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 4390208 T10231 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 4390209 T10231 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 4390209 T10231 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 4390209 T10231 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 4390210 T10231 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 4390210 T10231 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 4390211 T10231 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 4390211 T10231 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 4390222 T10231 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4390224 T10231 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4390226 T10231 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4390229 T10231 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4390234 T10231 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 4390234 T10231 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 4390235 T10231 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=45, maxMergeAtOnceExplicit=49, maxMergedSegmentMB=68.671875, floorSegmentMB=1.2470703125, forceMergeDeletesPctAllowed=9.543528728713706, segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0 [junit4] 2> 4390235 T10231 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-3f160ab0)),segFN=segments_1,generation=1} [junit4] 2> 4390236 T10231 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 4390236 T10231 oass.SolrIndexSearcher.<init> Opening Searcher@5736db5b[collection1] main [junit4] 2> 4390236 T10231 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 4390243 T10231 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 4390243 T10231 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 4390245 T10231 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 4390245 T10231 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 4390245 T10231 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 4390248 T10231 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json [junit4] 2> 4390248 T10231 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 4390248 T10231 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed [junit4] 2> 4390248 T10231 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 4390254 T10232 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5736db5b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 4390258 T10231 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 4390260 T10235 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55886/vhml/n collection:collection1 shard:shard1 [junit4] 2> 4390261 T10163 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0 [junit4] 2> 4390262 T10163 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 4390264 T10235 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 4390279 T10235 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1 [junit4] 2> 4390282 T10190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4390283 T10235 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue. [junit4] 2> 4390283 T10235 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync [junit4] 2> ASYNC NEW_CORE C2651 name=collection1 org.apache.solr.core.SolrCore@597c0d96 url=http://127.0.0.1:55886/vhml/n/collection1 node=127.0.0.1:55886_vhml%2Fn C2651_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:55886/vhml/n, node_name=127.0.0.1:55886_vhml%2Fn, core=collection1} [junit4] 2> 4390283 T10235 C2651 P55886 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55886/vhml/n/collection1/ [junit4] 2> 4390283 T10235 C2651 P55886 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me [junit4] 2> 4390284 T10235 C2651 P55886 oasc.SyncStrategy.syncToMe http://127.0.0.1:55886/vhml/n/collection1/ has no replicas [junit4] 2> 4390284 T10235 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55886/vhml/n/collection1/ shard1 [junit4] 2> 4390284 T10235 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 4390301 T10190 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 4390301 T10211 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 4390301 T10197 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 4390301 T10230 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 4390317 T10190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4390328 T10230 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 4390347 T10190 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 4390347 T10197 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 4390349 T10211 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 4390408 T10235 oasc.ZkController.register We are http://127.0.0.1:55886/vhml/n/collection1/ and leader is http://127.0.0.1:55886/vhml/n/collection1/ [junit4] 2> 4390408 T10235 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55886/vhml/n [junit4] 2> 4390408 T10235 oasc.ZkController.checkRecovery I am the leader, no recovery necessary [junit4] 2> 4390408 T10235 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1 [junit4] 2> 4390410 T10235 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 4390416 T10190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4390427 T10186 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "roles":null, [junit4] 2> "core_node_name":"core_node2", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://127.0.0.1:55886/vhml/n";, [junit4] 2> "numShards":"2", [junit4] 2> "node_name":"127.0.0.1:55886_vhml%2Fn", [junit4] 2> "core":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 4390542 T10190 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 4390542 T10211 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 4390542 T10197 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 4390542 T10230 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3) [junit4] 2> 4391933 T10163 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3 [junit4] 2> 4391934 T10163 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 4391940 T10163 oejs.AbstractConnector.doStart Started [email protected]:55895 [junit4] 2> 4391942 T10163 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 4391942 T10163 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 4391942 T10163 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-005 [junit4] 2> 4391942 T10163 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-005\' [junit4] 2> 4391980 T10163 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001\tempDir-005\solr.xml [junit4] 2> 4392048 T10163 oasc.CoreContainer.<init> New CoreContainer 514620928 [junit4] 2> 4392048 T10163 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\ [...truncated too long message...] concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2048) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:821) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1372) [junit4] 2> at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:110) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.process(SolrZkClient.java:263) [junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522) [junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498) [junit4] 2> [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=EE62A9CE06EE40E4 -Dtests.slow=true -Dtests.locale=ca -Dtests.timezone=SystemV/EST5 -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1 [junit4] FAILURE 62.4s | BasicDistributedZkTest.testDistribSearch <<< [junit4] > Throwable #1: java.lang.AssertionError: commitWithin did not work on node: http://127.0.0.1:55877/vhml/n/collection1 expected:<68> but was:<67> [junit4] > at __randomizedtesting.SeedInfo.seed([EE62A9CE06EE40E4:6F8427D671B120D8]:0) [junit4] > at org.apache.solr.cloud.BasicDistributedZkTest.doTest(BasicDistributedZkTest.java:345) [junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869) [junit4] > at java.lang.Thread.run(Thread.java:745) [junit4] 2> 4438128 T10163 oas.SolrTestCaseJ4.deleteCore ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-EE62A9CE06EE40E4-001 [junit4] 2> 62401 T10162 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s). [junit4] 2> NOTE: test params are: codec=Asserting(Lucene50): {multiDefault=Lucene50(blocksize=128), intDefault=BlockTreeOrds(blocksize=128), n_f1=Lucene50(blocksize=128), foo_b=PostingsFormat(name=Direct), range_facet_l=BlockTreeOrds(blocksize=128), SubjectTerms_mfacet=BlockTreeOrds(blocksize=128), a_t=BlockTreeOrds(blocksize=128), other_tl1=BlockTreeOrds(blocksize=128), n_ti1=PostingsFormat(name=MockRandom), id=PostingsFormat(name=MockRandom), foo_i=Lucene50(blocksize=128), n_dt1=Lucene50(blocksize=128), n_td1=Lucene50(blocksize=128), a_i1=BlockTreeOrds(blocksize=128), text=PostingsFormat(name=Direct), n_tf1=BlockTreeOrds(blocksize=128), n_l1=BlockTreeOrds(blocksize=128), _version_=BlockTreeOrds(blocksize=128), n_tdt1=BlockTreeOrds(blocksize=128), oddField_s=PostingsFormat(name=Direct), n_tl1=Lucene50(blocksize=128), foo_d=PostingsFormat(name=MockRandom), timestamp=BlockTreeOrds(blocksize=128), foo_f=PostingsFormat(name=Direct), n_d1=BlockTreeOrds(blocksize=128), rnd_b=PostingsFormat(name=MockRandom)}, docValues:{timestamp=DocValuesFormat(name=Asserting)}, sim=DefaultSimilarity, locale=ca, timezone=SystemV/EST5 [junit4] 2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_67 (64-bit)/cpus=2,threads=1,free=262056264,total=536870912 [junit4] 2> NOTE: All tests run in this JVM: [TestMiniSolrCloudCluster, FileBasedSpellCheckerTest, AnalysisAfterCoreReloadTest, TestLuceneMatchVersion, TestMultiCoreConfBootstrap, FieldMutatingUpdateProcessorTest, LeaderElectionTest, TestCodecSupport, ClusterStateTest, RecoveryZkTest, DistributedSuggestComponentTest, TestValueSourceCache, TestSystemIdResolver, XsltUpdateRequestHandlerTest, DocValuesTest, ZkNodePropsTest, OutputWriterTest, OpenExchangeRatesOrgProviderTest, TestCSVResponseWriter, TestReversedWildcardFilterFactory, AliasIntegrationTest, TestSolrQueryParserDefaultOperatorResource, TestFieldTypeCollectionResource, SuggestComponentTest, UUIDUpdateProcessorFallbackTest, TestRealTimeGet, ScriptEngineTest, TestReplicationHandlerBackup, TestRecovery, TestShortCircuitedRequests, TestCloudManagedSchema, DistributedDebugComponentTest, AtomicUpdatesTest, OverriddenZkACLAndCredentialsProvidersTest, TestWriterPerf, TestModifyConfFiles, TestSolrIndexConfig, LeaderFailoverAfterPartitionTest, ShardRoutingCustomTest, TestFuzzyAnalyzedSuggestions, TestDefaultSimilarityFactory, TestStressReorder, HdfsDirectoryTest, TriLevelCompositeIdRoutingTest, StatelessScriptUpdateProcessorFactoryTest, AlternateDirectoryTest, CacheHeaderTest, DocumentAnalysisRequestHandlerTest, TestMaxScoreQueryParser, TestSchemaNameResource, BadComponentTest, TestExtendedDismaxParser, TestFoldingMultitermQuery, TestInitQParser, TestImplicitCoreProperties, SpellPossibilityIteratorTest, TestReplicationHandler, TestLeaderElectionZkExpiry, TestFastLRUCache, TestSchemaManager, TestHighFrequencyDictionaryFactory, TestSurroundQueryParser, CircularListTest, HdfsWriteToMultipleCollectionsTest, PeerSyncTest, SSLMigrationTest, TestWordDelimiterFilterFactory, TestBinaryField, TestCloudSchemaless, TermVectorComponentDistributedTest, ZkSolrClientTest, TestSolrQueryParserResource, MigrateRouteKeyTest, PluginInfoTest, ResourceLoaderTest, DistribDocExpirationUpdateProcessorTest, TestRandomDVFaceting, TestGroupingSearch, TestComponentsName, TestStressLucene, TestNonNRTOpen, TestReRankQParserPlugin, TestInfoStreamLogging, ChaosMonkeyNothingIsSafeTest, DistributedQueryComponentCustomSortTest, TestManagedSchemaFieldTypeResource, TestConfigSets, HighlighterTest, HardAutoCommitTest, MoreLikeThisHandlerTest, SynonymTokenizerTest, SchemaVersionSpecificBehaviorTest, SolrXmlInZkTest, TestXIncludeConfig, DeleteShardTest, TestShardHandlerFactory, SuggesterTSTTest, TestExpandComponent, DistributedIntervalFacetingTest, TestChildDocTransformer, TestUpdate, ShardSplitTest, TestFieldResource, TestMissingGroups, NotRequiredUniqueKeyTest, TestJmxMonitoredMap, HighlighterConfigTest, TestSort, PathHierarchyTokenizerFactoryTest, CollectionsAPIDistributedZkTest, TestQueryUtils, TestBulkSchemaConcurrent, TestSearchPerf, AsyncMigrateRouteKeyTest, TestFunctionQuery, TestOmitPositions, ResponseLogComponentTest, HttpPartitionTest, TestManagedSchemaFieldResource, TestDistribDocBasedVersion, TestCloudInspectUtil, CursorMarkTest, SolrPluginUtilsTest, UpdateRequestProcessorFactoryTest, RollingRestartTest, SpatialFilterTest, TestCopyFieldCollectionResource, URLClassifyProcessorTest, FieldAnalysisRequestHandlerTest, HdfsSyncSliceTest, TestNRTOpen, SolrIndexSplitterTest, OutOfBoxZkACLAndCredentialsProvidersTest, SpellCheckComponentTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestHighlightDedupGrouping, TestIntervalFaceting, SyncSliceTest, JsonLoaderTest, TestPivotHelperCode, TermsComponentTest, StatsComponentTest, TestLMDirichletSimilarityFactory, TestExceedMaxTermLength, CopyFieldTest, LegacyHTMLStripCharFilterTest, RemoteQueryErrorTest, DOMUtilTest, TestRangeQuery, DistributedExpandComponentTest, CurrencyFieldXmlFileTest, MBeansHandlerTest, DeleteInactiveReplicaTest, AssignTest, TestFaceting, VMParamsZkACLAndCredentialsProvidersTest, TestCollectionAPI, QueryResultKeyTest, TestDistributedGrouping, DirectUpdateHandlerTest, IndexBasedSpellCheckerTest, LeaderElectionIntegrationTest, DistributedTermsComponentTest, TestDistributedMissingSort, TestCustomSort, SliceStateTest, DateMathParserTest, TestNoOpRegenerator, AnalyticsMergeStrategyTest, DistribCursorPagingTest, AddBlockUpdateTest, TestJoin, BasicFunctionalityTest, TestJmxIntegration, SOLR749Test, SpellCheckCollatorTest, TestQuerySenderNoQuery, TestRestManager, TestQueryTypes, ConvertedLegacyTest, TestFreeTextSuggestions, TestSolrXml, DateFieldTest, TestFieldCollectionResource, TestSolrXmlPersistor, OverseerTest, TestFieldTypeResource, SystemInfoHandlerTest, PrimitiveFieldTypeTest, MultiTermTest, QueryEqualityTest, ModifyConfFileTest, TestSchemaSimilarityResource, TestLRUCache, SolrInfoMBeanTest, ResponseHeaderTest, StandardRequestHandlerTest, HdfsRecoveryZkTest, TestSearcherReuse, TestManagedSynonymFilterFactory, ChangedSchemaMergeTest, TestQuerySenderListener, ReplicationFactorTest, TestPartialUpdateDeduplication, SampleTest, DistributedQueryElevationComponentTest, SuggesterWFSTTest, TestMergePolicyConfig, TestLMJelinekMercerSimilarityFactory, TestDocBasedVersionConstraints, EnumFieldTest, TestManagedSchema, DocExpirationUpdateProcessorFactoryTest, CloudExitableDirectoryReaderTest, BasicDistributedZkTest] [junit4] Completed in 62.74s, 1 test, 1 failure <<< FAILURES! [...truncated 739 lines...] BUILD FAILED C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:525: The following error occurred while executing this line: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:473: The following error occurred while executing this line: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:61: The following error occurred while executing this line: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\extra-targets.xml:39: The following error occurred while executing this line: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:189: The following error occurred while executing this line: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:496: The following error occurred while executing this line: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1358: The following error occurred while executing this line: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:965: There were test failures: 437 suites, 1796 tests, 1 failure, 53 ignored (30 assumptions) Total time: 189 minutes 40 seconds Build step 'Invoke Ant' marked build as failure [description-setter] Description set: Java: 64bit/jdk1.7.0_67 -XX:-UseCompressedOops -XX:+UseG1GC 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]
