Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/4399/ Java: 32bit/jdk1.7.0_67 -server -XX:+UseConcMarkSweepGC
1 tests failed. REGRESSION: org.apache.solr.cloud.BasicDistributedZkTest.testDistribSearch Error Message: commitWithin did not work on node: http://127.0.0.1:54805/collection1 expected:<68> but was:<67> Stack Trace: java.lang.AssertionError: commitWithin did not work on node: http://127.0.0.1:54805/collection1 expected:<68> but was:<67> at __randomizedtesting.SeedInfo.seed([25C8DFA7ACA6E6F5:A42E51BFDBF986C9]: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.GeneratedMethodAccessor67.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 11058 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-25C8DFA7ACA6E6F5-001\init-core-data-001 [junit4] 2> 4208755 T9658 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: / [junit4] 2> 4208760 T9658 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch [junit4] 2> 4208762 T9658 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 4208764 T9659 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 4208860 T9658 oasc.ZkTestServer.run start zk server on port:54768 [junit4] 2> 4208860 T9658 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 4208863 T9658 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 4208867 T9665 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@160be17 name:ZooKeeperConnection Watcher:127.0.0.1:54768 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 4208868 T9658 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 4208868 T9658 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 4208868 T9658 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 4208874 T9658 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 4208876 T9658 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 4208878 T9667 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f096a1 name:ZooKeeperConnection Watcher:127.0.0.1:54768/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 4208879 T9658 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 4208879 T9658 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 4208879 T9658 oascc.SolrZkClient.makePath makePath: /collections/collection1 [junit4] 2> 4208888 T9658 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards [junit4] 2> 4208896 T9658 oascc.SolrZkClient.makePath makePath: /collections/control_collection [junit4] 2> 4208904 T9658 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards [junit4] 2> 4208909 T9658 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> 4208910 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml [junit4] 2> 4208917 T9658 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> 4208917 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml [junit4] 2> 4208924 T9658 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> 4208924 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 4208931 T9658 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> 4208931 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt [junit4] 2> 4208937 T9658 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> 4208937 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt [junit4] 2> 4208942 T9658 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> 4208942 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml [junit4] 2> 4208948 T9658 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> 4208948 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml [junit4] 2> 4208954 T9658 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> 4208954 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json [junit4] 2> 4208959 T9658 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> 4208960 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 4208965 T9658 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> 4208965 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt [junit4] 2> 4208970 T9658 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> 4208972 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt [junit4] 2> 4210939 T9658 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 4210950 T9658 oejs.AbstractConnector.doStart Started [email protected]:54775 [junit4] 2> 4210950 T9658 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 4210950 T9658 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 4210950 T9658 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-25C8DFA7ACA6E6F5-001\tempDir-002 [junit4] 2> 4210950 T9658 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-25C8DFA7ACA6E6F5-001\tempDir-002\' [junit4] 2> 4210993 T9658 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-25C8DFA7ACA6E6F5-001\tempDir-002\solr.xml [junit4] 2> 4211106 T9658 oasc.CoreContainer.<init> New CoreContainer 1222590 [junit4] 2> 4211106 T9658 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-25C8DFA7ACA6E6F5-001\tempDir-002\] [junit4] 2> 4211110 T9658 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 4211110 T9658 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 4211110 T9658 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 4211110 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 4211110 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000 [junit4] 2> 4211110 T9658 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 4211110 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 4211110 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 4211111 T9658 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 4211111 T9658 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 4211111 T9658 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 4211114 T9658 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 4211114 T9658 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 4211114 T9658 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 4211114 T9658 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54768/solr [junit4] 2> 4211114 T9658 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 4211114 T9658 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 4211118 T9658 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 4211121 T9678 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c2c293 name:ZooKeeperConnection Watcher:127.0.0.1:54768 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 4211122 T9658 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 4211122 T9658 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 4211127 T9658 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 4211147 T9680 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@103cd8c name:ZooKeeperConnection Watcher:127.0.0.1:54768/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 4211148 T9658 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 4211150 T9658 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 4211156 T9658 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 4211162 T9658 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 4211168 T9658 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 4211174 T9658 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 4211180 T9658 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 4211184 T9658 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54775_ [junit4] 2> 4211185 T9658 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54775_ [junit4] 2> 4211191 T9658 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 4211195 T9658 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 4211200 T9658 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 4211204 T9658 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:54775_ [junit4] 2> 4211204 T9658 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 4211208 T9658 oasc.Overseer.start Overseer (id=92711792594124803-127.0.0.1:54775_-n_0000000000) starting [junit4] 2> 4211213 T9658 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 4211233 T9658 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 4211235 T9682 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 4211237 T9658 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 4211243 T9658 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 4211247 T9658 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 4211255 T9681 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 4211261 T9684 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection [junit4] 2> 4211262 T9684 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 4211262 T9684 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 4211263 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4211269 T9681 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "roles":null, [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:54775";, [junit4] 2> "numShards":"1", [junit4] 2> "node_name":"127.0.0.1:54775_", [junit4] 2> "collection":"control_collection", [junit4] 2> "shard":null, [junit4] 2> "operation":"state", [junit4] 2> "core":"collection1"} [junit4] 2> 4211269 T9681 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1] [junit4] 2> 4211269 T9681 oasc.Overseer$ClusterStateUpdater.createCollection state version control_collection 1 [junit4] 2> 4211269 T9681 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 4211275 T9685 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> 4212301 T9684 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 4212301 T9684 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection [junit4] 2> 4212302 T9684 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 4212302 T9684 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection [junit4] 2> 4212305 T9684 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper [junit4] 2> 4212305 T9684 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-25C8DFA7ACA6E6F5-001\tempDir-002\collection1\' [junit4] 2> 4212308 T9684 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001/tempDir-002/collection1/lib/.svn/' to classloader [junit4] 2> 4212311 T9684 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001/tempDir-002/collection1/lib/classes/' to classloader [junit4] 2> 4212313 T9684 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001/tempDir-002/collection1/lib/README' to classloader [junit4] 2> 4212386 T9684 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0 [junit4] 2> 4212453 T9684 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 4212456 T9684 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml [junit4] 2> 4212465 T9684 oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 4212903 T9684 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 4212912 T9684 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 4212915 T9684 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 4212949 T9684 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 4212954 T9684 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 4212959 T9684 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 4212961 T9684 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 4212962 T9684 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 4212962 T9684 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 4212964 T9684 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 4212964 T9684 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 4212964 T9684 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection [junit4] 2> 4212964 T9684 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 4212966 T9684 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-25C8DFA7ACA6E6F5-001\tempDir-002\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-001/control/data\ [junit4] 2> 4212966 T9684 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@17f8627 [junit4] 2> 4212967 T9684 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-25C8DFA7ACA6E6F5-001\tempDir-001/control/data\ [junit4] 2> 4212967 T9684 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-25C8DFA7ACA6E6F5-001\tempDir-001/control/data\index/ [junit4] 2> 4212967 T9684 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-25C8DFA7ACA6E6F5-001\tempDir-001\control\data\index' doesn't exist. Creating new index... [junit4] 2> 4212968 T9684 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-25C8DFA7ACA6E6F5-001\tempDir-001/control/data\index [junit4] 2> 4212968 T9684 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=22, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0] [junit4] 2> 4212969 T9684 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1f322b5)),segFN=segments_1,generation=1} [junit4] 2> 4212969 T9684 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 4212973 T9684 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 4212973 T9684 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 4212973 T9684 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 4212974 T9684 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 4212974 T9684 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 4212974 T9684 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 4212975 T9684 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 4212975 T9684 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 4212975 T9684 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 4212976 T9684 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 4212976 T9684 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 4212977 T9684 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 4212977 T9684 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 4212977 T9684 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 4212978 T9684 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 4212978 T9684 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 4212978 T9684 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 4212979 T9684 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 4212979 T9684 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 4212979 T9684 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 4212993 T9684 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4212995 T9684 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4212999 T9684 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4213001 T9684 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4213010 T9684 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 4213010 T9684 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 4213012 T9684 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=64.41015625, floorSegmentMB=0.203125, forceMergeDeletesPctAllowed=16.00541628600708, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8234737136161981 [junit4] 2> 4213013 T9684 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1f322b5)),segFN=segments_1,generation=1} [junit4] 2> 4213013 T9684 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 4213014 T9684 oass.SolrIndexSearcher.<init> Opening Searcher@e3f2d1[collection1] main [junit4] 2> 4213014 T9684 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection [junit4] 2> 4213016 T9684 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper [junit4] 2> 4213016 T9684 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 4213018 T9684 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 4213018 T9684 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 4213018 T9684 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 4213019 T9684 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json [junit4] 2> 4213019 T9684 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 4213021 T9684 oascc.SolrZkClient.makePath makePath: /configs/conf1/_rest_managed.json [junit4] 2> 4213025 T9684 oasr.ManagedResourceStorage$ZooKeeperStorageIO$1.close Wrote 38 bytes to new znode /configs/conf1/_rest_managed.json [junit4] 2> 4213025 T9684 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 4213025 T9684 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 4213028 T9686 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e3f2d1[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 4213030 T9684 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 4213032 T9689 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54775 collection:control_collection shard:shard1 [junit4] 2> 4213032 T9658 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0 [junit4] 2> 4213033 T9658 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 4213034 T9658 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 4213035 T9689 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election [junit4] 2> 4213036 T9658 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 4213038 T9691 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d62f0a name:ZooKeeperConnection Watcher:127.0.0.1:54768/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 4213039 T9658 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 4213039 T9658 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 4213041 T9658 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 4213049 T9689 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1 [junit4] 2> 4213051 T9658 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false [junit4] 2> 4213054 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4213057 T9689 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue. [junit4] 2> 4213057 T9689 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync [junit4] 2> ASYNC NEW_CORE C4634 name=collection1 org.apache.solr.core.SolrCore@10af15b url=http://127.0.0.1:54775/collection1 node=127.0.0.1:54775_ C4634_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:54775, node_name=127.0.0.1:54775_, core=collection1} [junit4] 2> 4213057 T9689 C4634 P54775 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54775/collection1/ [junit4] 2> 4213057 T9689 C4634 P54775 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me [junit4] 2> 4213057 T9689 C4634 P54775 oasc.SyncStrategy.syncToMe http://127.0.0.1:54775/collection1/ has no replicas [junit4] 2> 4213058 T9689 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54775/collection1/ shard1 [junit4] 2> 4213059 T9689 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1 [junit4] 2> 4213082 T9685 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> 4213087 T9692 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> 4213118 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4213120 T9685 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> 4213121 T9692 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> 4213138 T9689 oasc.ZkController.register We are http://127.0.0.1:54775/collection1/ and leader is http://127.0.0.1:54775/collection1/ [junit4] 2> 4213138 T9689 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54775 [junit4] 2> 4213138 T9689 oasc.ZkController.checkRecovery I am the leader, no recovery necessary [junit4] 2> 4213138 T9689 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection [junit4] 2> 4213138 T9689 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 4213141 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4213159 T9681 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "roles":null, [junit4] 2> "state":"active", [junit4] 2> "base_url":"http://127.0.0.1:54775";, [junit4] 2> "numShards":"2", [junit4] 2> "node_name":"127.0.0.1:54775_", [junit4] 2> "collection":"control_collection", [junit4] 2> "shard":"shard1", [junit4] 2> "operation":"state", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "core":"collection1"} [junit4] 2> 4213282 T9685 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> 4213282 T9692 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> 4214723 T9658 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1 [junit4] 2> 4214724 T9658 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 4214729 T9658 oejs.AbstractConnector.doStart Started [email protected]:54787 [junit4] 2> 4214730 T9658 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 4214730 T9658 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 4214730 T9658 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-25C8DFA7ACA6E6F5-001\tempDir-003 [junit4] 2> 4214731 T9658 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-25C8DFA7ACA6E6F5-001\tempDir-003\' [junit4] 2> 4214764 T9658 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-25C8DFA7ACA6E6F5-001\tempDir-003\solr.xml [junit4] 2> 4214828 T9658 oasc.CoreContainer.<init> New CoreContainer 2565472 [junit4] 2> 4214828 T9658 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-25C8DFA7ACA6E6F5-001\tempDir-003\] [junit4] 2> 4214830 T9658 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 4214831 T9658 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 4214831 T9658 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 4214831 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 4214831 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000 [junit4] 2> 4214831 T9658 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 4214831 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 4214831 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 4214833 T9658 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 4214833 T9658 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 4214833 T9658 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 4214833 T9658 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 4214833 T9658 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 4214836 T9658 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 4214836 T9658 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54768/solr [junit4] 2> 4214836 T9658 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 4214836 T9658 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 4214840 T9658 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 4214841 T9703 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6c2ba name:ZooKeeperConnection Watcher:127.0.0.1:54768 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 4214842 T9658 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 4214842 T9658 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 4214845 T9660 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14960e258100005, 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> 4214848 T9658 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 4214849 T9705 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1dee4d9 name:ZooKeeperConnection Watcher:127.0.0.1:54768/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 4214849 T9658 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 4214862 T9658 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 4215921 T9658 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54787_ [junit4] 2> 4215921 T9658 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54787_ [junit4] 2> 4215929 T9658 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 4215949 T9707 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1 [junit4] 2> 4215949 T9707 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 4215951 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4215951 T9707 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 4215957 T9681 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "roles":null, [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:54787";, [junit4] 2> "numShards":"2", [junit4] 2> "node_name":"127.0.0.1:54787_", [junit4] 2> "collection":"collection1", [junit4] 2> "shard":null, [junit4] 2> "operation":"state", [junit4] 2> "core":"collection1"} [junit4] 2> 4215957 T9681 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2] [junit4] 2> 4215959 T9681 oasc.Overseer$ClusterStateUpdater.createCollection state version collection1 1 [junit4] 2> 4215959 T9681 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2 [junit4] 2> 4215965 T9706 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> 4215965 T9685 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> 4215965 T9692 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> 4217001 T9707 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 4217001 T9707 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1 [junit4] 2> 4217002 T9707 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 4217003 T9707 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 4217005 T9707 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 4217005 T9707 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-25C8DFA7ACA6E6F5-001\tempDir-003\collection1\' [junit4] 2> 4217007 T9707 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001/tempDir-003/collection1/lib/.svn/' to classloader [junit4] 2> 4217007 T9707 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001/tempDir-003/collection1/lib/classes/' to classloader [junit4] 2> 4217007 T9707 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001/tempDir-003/collection1/lib/README' to classloader [junit4] 2> 4217068 T9707 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0 [junit4] 2> 4217116 T9707 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 4217118 T9707 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml [junit4] 2> 4217127 T9707 oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 4217625 T9707 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 4217637 T9707 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 4217640 T9707 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 4217662 T9707 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 4217668 T9707 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 4217674 T9707 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 4217677 T9707 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 4217678 T9707 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 4217678 T9707 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 4217680 T9707 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 4217680 T9707 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 4217681 T9707 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 4217681 T9707 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 4217681 T9707 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-25C8DFA7ACA6E6F5-001\tempDir-003\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-001/jetty1\ [junit4] 2> 4217682 T9707 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@17f8627 [junit4] 2> 4217682 T9707 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-25C8DFA7ACA6E6F5-001\tempDir-001/jetty1\ [junit4] 2> 4217683 T9707 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-25C8DFA7ACA6E6F5-001\tempDir-001/jetty1\index/ [junit4] 2> 4217683 T9707 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-25C8DFA7ACA6E6F5-001\tempDir-001\jetty1\index' doesn't exist. Creating new index... [junit4] 2> 4217683 T9707 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-25C8DFA7ACA6E6F5-001\tempDir-001/jetty1\index [junit4] 2> 4217684 T9707 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=22, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0] [junit4] 2> 4217684 T9707 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-b77287)),segFN=segments_1,generation=1} [junit4] 2> 4217685 T9707 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 4217689 T9707 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 4217690 T9707 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 4217690 T9707 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 4217691 T9707 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 4217691 T9707 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 4217691 T9707 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 4217692 T9707 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 4217692 T9707 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 4217692 T9707 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 4217693 T9707 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 4217693 T9707 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 4217694 T9707 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 4217694 T9707 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 4217696 T9707 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 4217696 T9707 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 4217696 T9707 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 4217698 T9707 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 4217698 T9707 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 4217699 T9707 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 4217699 T9707 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 4217712 T9707 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4217714 T9707 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4217717 T9707 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4217719 T9707 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4217724 T9707 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 4217724 T9707 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 4217725 T9707 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=64.41015625, floorSegmentMB=0.203125, forceMergeDeletesPctAllowed=16.00541628600708, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8234737136161981 [junit4] 2> 4217726 T9707 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-b77287)),segFN=segments_1,generation=1} [junit4] 2> 4217726 T9707 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 4217726 T9707 oass.SolrIndexSearcher.<init> Opening Searcher@15fd274[collection1] main [junit4] 2> 4217726 T9707 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 4217729 T9707 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 4217729 T9707 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 4217731 T9707 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 4217731 T9707 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 4217731 T9707 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 4217733 T9707 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json [junit4] 2> 4217733 T9707 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 4217733 T9707 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed [junit4] 2> 4217733 T9707 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 4217742 T9708 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@15fd274[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 4217746 T9707 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 4217748 T9711 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54787 collection:collection1 shard:shard2 [junit4] 2> 4217749 T9658 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0 [junit4] 2> 4217749 T9658 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 4217751 T9711 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election [junit4] 2> 4217766 T9711 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2 [junit4] 2> 4217769 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4217770 T9711 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue. [junit4] 2> 4217770 T9711 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync [junit4] 2> ASYNC NEW_CORE C4635 name=collection1 org.apache.solr.core.SolrCore@712d79 url=http://127.0.0.1:54787/collection1 node=127.0.0.1:54787_ C4635_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:54787, node_name=127.0.0.1:54787_, core=collection1} [junit4] 2> 4217770 T9711 C4635 P54787 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54787/collection1/ [junit4] 2> 4217770 T9711 C4635 P54787 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me [junit4] 2> 4217770 T9711 C4635 P54787 oasc.SyncStrategy.syncToMe http://127.0.0.1:54787/collection1/ has no replicas [junit4] 2> 4217772 T9711 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54787/collection1/ shard2 [junit4] 2> 4217772 T9711 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2 [junit4] 2> 4217799 T9685 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> 4217799 T9692 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> 4217800 T9706 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> 4217828 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4217831 T9685 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> 4217831 T9706 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> 4217833 T9692 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> 4217852 T9711 oasc.ZkController.register We are http://127.0.0.1:54787/collection1/ and leader is http://127.0.0.1:54787/collection1/ [junit4] 2> 4217852 T9711 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54787 [junit4] 2> 4217852 T9711 oasc.ZkController.checkRecovery I am the leader, no recovery necessary [junit4] 2> 4217852 T9711 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1 [junit4] 2> 4217852 T9711 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 4217855 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4217867 T9681 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "roles":null, [junit4] 2> "state":"active", [junit4] 2> "base_url":"http://127.0.0.1:54787";, [junit4] 2> "numShards":"2", [junit4] 2> "node_name":"127.0.0.1:54787_", [junit4] 2> "collection":"collection1", [junit4] 2> "shard":"shard2", [junit4] 2> "operation":"state", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "core":"collection1"} [junit4] 2> 4217980 T9685 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> 4217981 T9692 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> 4217982 T9706 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> 4219630 T9658 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2 [junit4] 2> 4219631 T9658 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 4219635 T9658 oejs.AbstractConnector.doStart Started [email protected]:54796 [junit4] 2> 4219637 T9658 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 4219638 T9658 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 4219638 T9658 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-25C8DFA7ACA6E6F5-001\tempDir-004 [junit4] 2> 4219639 T9658 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-25C8DFA7ACA6E6F5-001\tempDir-004\' [junit4] 2> 4219684 T9658 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-25C8DFA7ACA6E6F5-001\tempDir-004\solr.xml [junit4] 2> 4219769 T9658 oasc.CoreContainer.<init> New CoreContainer 7308798 [junit4] 2> 4219769 T9658 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-25C8DFA7ACA6E6F5-001\tempDir-004\] [junit4] 2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000 [junit4] 2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 4219775 T9658 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 4219775 T9658 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 4219775 T9658 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 4219775 T9658 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 4219775 T9658 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54768/solr [junit4] 2> 4219778 T9658 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 4219778 T9658 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 4219780 T9658 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 4219783 T9722 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c5eb05 name:ZooKeeperConnection Watcher:127.0.0.1:54768 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 4219784 T9658 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 4219784 T9658 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 4219789 T9658 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 4219791 T9724 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3dc324 name:ZooKeeperConnection Watcher:127.0.0.1:54768/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 4219791 T9658 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 4219803 T9658 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 4220862 T9658 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54796_ [junit4] 2> 4220863 T9658 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54796_ [junit4] 2> 4220871 T9658 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 4220881 T9726 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1 [junit4] 2> 4220881 T9726 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 4220882 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4220884 T9726 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 4220888 T9681 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "roles":null, [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:54796";, [junit4] 2> "numShards":"2", [junit4] 2> "node_name":"127.0.0.1:54796_", [junit4] 2> "collection":"collection1", [junit4] 2> "shard":null, [junit4] 2> "operation":"state", [junit4] 2> "core":"collection1"} [junit4] 2> 4220889 T9681 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2 [junit4] 2> 4220889 T9681 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 4220893 T9685 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> 4220893 T9706 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> 4220893 T9725 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> 4220893 T9692 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> 4221938 T9726 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 4221938 T9726 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1 [junit4] 2> 4221941 T9726 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 4221941 T9726 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 4221943 T9726 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 4221943 T9726 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-25C8DFA7ACA6E6F5-001\tempDir-004\collection1\' [junit4] 2> 4221946 T9726 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001/tempDir-004/collection1/lib/.svn/' to classloader [junit4] 2> 4221948 T9726 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001/tempDir-004/collection1/lib/classes/' to classloader [junit4] 2> 4221949 T9726 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001/tempDir-004/collection1/lib/README' to classloader [junit4] 2> 4222036 T9726 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0 [junit4] 2> 4222109 T9726 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 4222111 T9726 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml [junit4] 2> 4222124 T9726 oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 4222577 T9726 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 4222594 T9726 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 4222600 T9726 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 4222626 T9726 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 4222633 T9726 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 4222640 T9726 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 4222642 T9726 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 4222642 T9726 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 4222642 T9726 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 4222645 T9726 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 4222645 T9726 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 4222645 T9726 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 4222645 T9726 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 4222646 T9726 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-25C8DFA7ACA6E6F5-001\tempDir-004\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-001/jetty2\ [junit4] 2> 4222646 T9726 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@17f8627 [junit4] 2> 4222647 T9726 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-25C8DFA7ACA6E6F5-001\tempDir-001/jetty2\ [junit4] 2> 4222647 T9726 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-25C8DFA7ACA6E6F5-001\tempDir-001/jetty2\index/ [junit4] 2> 4222647 T9726 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-25C8DFA7ACA6E6F5-001\tempDir-001\jetty2\index' doesn't exist. Creating new index... [junit4] 2> 4222647 T9726 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-25C8DFA7ACA6E6F5-001\tempDir-001/jetty2\index [junit4] 2> 4222649 T9726 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=22, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0] [junit4] 2> 4222649 T9726 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-16dbcc2)),segFN=segments_1,generation=1} [junit4] 2> 4222649 T9726 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 4222655 T9726 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 4222656 T9726 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 4222656 T9726 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 4222656 T9726 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 4222656 T9726 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 4222656 T9726 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 4222658 T9726 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 4222658 T9726 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 4222658 T9726 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 4222659 T9726 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 4222659 T9726 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 4222660 T9726 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 4222660 T9726 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 4222661 T9726 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 4222661 T9726 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 4222661 T9726 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 4222662 T9726 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 4222662 T9726 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 4222663 T9726 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 4222663 T9726 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 4222675 T9726 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4222675 T9726 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4222678 T9726 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4222681 T9726 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 4222687 T9726 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 4222688 T9726 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 4222689 T9726 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=64.41015625, floorSegmentMB=0.203125, forceMergeDeletesPctAllowed=16.00541628600708, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8234737136161981 [junit4] 2> 4222689 T9726 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-16dbcc2)),segFN=segments_1,generation=1} [junit4] 2> 4222689 T9726 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 4222690 T9726 oass.SolrIndexSearcher.<init> Opening Searcher@620c67[collection1] main [junit4] 2> 4222690 T9726 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 4222693 T9726 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 4222693 T9726 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 4222694 T9726 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 4222694 T9726 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 4222694 T9726 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 4222697 T9726 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json [junit4] 2> 4222697 T9726 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 4222697 T9726 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed [junit4] 2> 4222697 T9726 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 4222702 T9727 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@620c67[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 4222704 T9726 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 4222706 T9730 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54796 collection:collection1 shard:shard1 [junit4] 2> 4222707 T9658 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0 [junit4] 2> 4222709 T9658 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 4222711 T9730 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 4222735 T9730 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1 [junit4] 2> 4222740 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4222743 T9730 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue. [junit4] 2> 4222743 T9730 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync [junit4] 2> ASYNC NEW_CORE C4636 name=collection1 org.apache.solr.core.SolrCore@8f4a84 url=http://127.0.0.1:54796/collection1 node=127.0.0.1:54796_ C4636_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:54796, node_name=127.0.0.1:54796_, core=collection1} [junit4] 2> 4222743 T9730 C4636 P54796 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54796/collection1/ [junit4] 2> 4222743 T9730 C4636 P54796 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me [junit4] 2> 4222743 T9730 C4636 P54796 oasc.SyncStrategy.syncToMe http://127.0.0.1:54796/collection1/ has no replicas [junit4] 2> 4222744 T9730 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54796/collection1/ shard1 [junit4] 2> 4222746 T9730 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 4222792 T9725 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> 4222794 T9685 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> 4222794 T9706 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> 4222795 T9692 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> 4222834 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4222837 T9685 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> 4222838 T9706 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> 4222838 T9692 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> 4222839 T9725 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> 4222852 T9730 oasc.ZkController.register We are http://127.0.0.1:54796/collection1/ and leader is http://127.0.0.1:54796/collection1/ [junit4] 2> 4222852 T9730 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54796 [junit4] 2> 4222852 T9730 oasc.ZkController.checkRecovery I am the leader, no recovery necessary [junit4] 2> 4222852 T9730 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1 [junit4] 2> 4222852 T9730 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 4222862 T9731 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 4222867 T9681 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "roles":null, [junit4] 2> "state":"active", [junit4] 2> "base_url":"http://127.0.0.1:54796";, [junit4] 2> "numShards":"2", [junit4] 2> "node_name":"127.0.0.1:54796_", [junit4] 2> "collection":"collection1", [junit4] 2> "shard":"shard1", [junit4] 2> "operation":"state", [junit4] 2> "core_node_name":"core_node2", [junit4] 2> "core":"collection1"} [junit4] 2> 4222989 T9731 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> 4222990 T9725 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> 4222990 T9706 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> 4222992 T9692 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> 4224789 T9658 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3 [junit4] 2> 4224790 T9658 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 4224797 T9658 oejs.AbstractConnector.doStart Started [email protected]:54805 [junit4] 2> 4224799 T9658 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 4224799 T9658 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 4224799 T9658 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-25C8DFA7ACA6E6F5-001\tempDir-005 [junit4] 2> 4224799 T9658 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-005\' [junit4] 2> 4224849 T9658 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-25C8DFA7ACA6E6F5-001\tempDir-005\solr.xml [junit4] 2> 4224971 T9658 oasc.CoreContainer.<init> New CoreContainer 29881098 [junit4] 2> 4224972 T9658 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-25C8DFA7ACA6E6F5-001\tempDir-005\] [junit4] 2> 4224974 T9658 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 4224975 T9658 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 4224975 T9658 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 4224975 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 4224976 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000 [junit4] 2> 4224976 T9658 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 4224978 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 4224978 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 4224979 T9658 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [...truncated too long message...] mmon.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> 4281129 T9800 oaz.ClientCnxn$EventThread.processEvent ERROR Error while calling watcher java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.FutureTask@1ff16d7 rejected from java.util.concurrent.ThreadPoolExecutor@1be86a0[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 16] [junit4] 2> at java.util.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=25C8DFA7ACA6E6F5 -Dtests.slow=true -Dtests.locale=es_EC -Dtests.timezone=Indian/Maldives -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [junit4] FAILURE 72.4s | BasicDistributedZkTest.testDistribSearch <<< [junit4] > Throwable #1: java.lang.AssertionError: commitWithin did not work on node: http://127.0.0.1:54805/collection1 expected:<68> but was:<67> [junit4] > at __randomizedtesting.SeedInfo.seed([25C8DFA7ACA6E6F5:A42E51BFDBF986C9]: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> 4281140 T9658 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-25C8DFA7ACA6E6F5-001 [junit4] 2> 72391 T9657 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s). [junit4] 2> NOTE: test params are: codec=Asserting(Lucene50): {id=PostingsFormat(name=Direct), foo_b=PostingsFormat(name=LuceneVarGapFixedInterval), _version_=BlockTreeOrds(blocksize=128), foo_f=PostingsFormat(name=LuceneVarGapFixedInterval), foo_i=BlockTreeOrds(blocksize=128), other_tl1=BlockTreeOrds(blocksize=128), SubjectTerms_mfacet=BlockTreeOrds(blocksize=128), n_tl1=BlockTreeOrds(blocksize=128), n_d1=PostingsFormat(name=LuceneVarGapDocFreqInterval), timestamp=PostingsFormat(name=LuceneVarGapDocFreqInterval), n_dt1=BlockTreeOrds(blocksize=128), foo_d=PostingsFormat(name=Direct), n_tdt1=BlockTreeOrds(blocksize=128), n_f1=BlockTreeOrds(blocksize=128), intDefault=BlockTreeOrds(blocksize=128), a_i1=PostingsFormat(name=LuceneVarGapDocFreqInterval), rnd_b=PostingsFormat(name=Direct), n_tf1=PostingsFormat(name=LuceneVarGapDocFreqInterval), n_l1=PostingsFormat(name=LuceneVarGapDocFreqInterval), multiDefault=PostingsFormat(name=LuceneVarGapDocFreqInterval), a_t=PostingsFormat(name=LuceneVarGapDocFreqInterval), text=PostingsFormat(name=LuceneVarGapFixedInterval), n_ti1=PostingsFormat(name=Direct), n_td1=BlockTreeOrds(blocksize=128), oddField_s=PostingsFormat(name=Direct), range_facet_l=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{timestamp=DocValuesFormat(name=SimpleText)}, sim=DefaultSimilarity, locale=es_EC, timezone=Indian/Maldives [junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_67 (32-bit)/cpus=2,threads=1,free=222459448,total=523501568 [junit4] 2> NOTE: All tests run in this JVM: [DirectUpdateHandlerOptimizeTest, TestInitParams, AnalysisAfterCoreReloadTest, TestBulkSchemaAPI, TestCollationFieldDocValues, NumericFieldsTest, TestManagedSchemaFieldResource, ShardRoutingTest, BadCopyFieldTest, StatelessScriptUpdateProcessorFactoryTest, CSVRequestHandlerTest, OverseerRolesTest, BlockDirectoryTest, UUIDFieldTest, TestPerFieldSimilarity, TestCopyFieldCollectionResource, TestTrie, TestFieldTypeCollectionResource, DisMaxRequestHandlerTest, EnumFieldTest, PreAnalyzedUpdateProcessorTest, TestRangeQuery, ExitableDirectoryReaderTest, TestSchemaResource, DistributedDebugComponentTest, DateMathParserTest, TestCoreDiscovery, TestXIncludeConfig, RecoveryZkTest, UnloadDistributedZkTest, TestShortCircuitedRequests, ShowFileRequestHandlerTest, StandardRequestHandlerTest, TestCollapseQParserPlugin, TestRandomMergePolicy, SortByFunctionTest, PeerSyncTest, TestInitQParser, ConvertedLegacyTest, TestComplexPhraseQParserPlugin, TestSimpleQParserPlugin, DistributedSpellCheckComponentTest, LeaderElectionTest, DistributedFacetPivotSmallTest, TestCloudManagedSchemaConcurrent, UpdateParamsTest, UniqFieldsUpdateProcessorFactoryTest, PreAnalyzedFieldTest, TestFunctionQuery, TestSurroundQueryParser, DistributedQueryComponentOptimizationTest, SolrCmdDistributorTest, UUIDUpdateProcessorFallbackTest, TestReplicaProperties, TestIndexSearcher, TestIntervalFaceting, TestReplicationHandler, CoreAdminRequestStatusTest, SolrIndexConfigTest, FullSolrCloudDistribCmdsTest, MultiTermTest, InfoHandlerTest, TestCoreContainer, EchoParamsTest, TestExceedMaxTermLength, TestManagedResource, JsonLoaderTest, TestRecoveryHdfs, TestDistributedSearch, ShardSplitTest, ClusterStateUpdateTest, CursorMarkTest, TestManagedResourceStorage, HdfsUnloadDistributedZkTest, TestSolrCoreProperties, TestQuerySenderNoQuery, HdfsDirectoryTest, TestAddFieldRealTimeGet, DocValuesTest, TestElisionMultitermQuery, TestSolrIndexConfig, RequiredFieldsTest, TestExtendedDismaxParser, TestSolrDeletionPolicy1, TestExpandComponent, BasicDistributedZk2Test, LeaderInitiatedRecoveryOnCommitTest, TestManagedSynonymFilterFactory, TestBinaryResponseWriter, CoreAdminCreateDiscoverTest, SharedFSAutoReplicaFailoverTest, HdfsChaosMonkeySafeLeaderTest, AddBlockUpdateTest, TestRTGBase, TestSolr4Spatial, TestConfig, SolrCoreTest, DistributedFacetPivotLongTailTest, IndexSchemaRuntimeFieldTest, MigrateRouteKeyTest, TestSchemaNameResource, TestShardHandlerFactory, RankQueryTest, ZkControllerTest, TestArbitraryIndexDir, SolrInfoMBeanTest, OutputWriterTest, TestGroupingSearch, TestMultiCoreConfBootstrap, SSLMigrationTest, TestSchemaManager, TestSearcherReuse, XmlUpdateRequestHandlerTest, FileBasedSpellCheckerTest, HttpPartitionTest, RollingRestartTest, PingRequestHandlerTest, DistribCursorPagingTest, DistributedQueryElevationComponentTest, TestNonDefinedSimilarityFactory, SimpleFacetsTest, SolrCoreCheckLockOnStartupTest, BasicFunctionalityTest, TestManagedSchemaFieldTypeResource, DeleteReplicaTest, DistributedExpandComponentTest, CollectionsAPIAsyncDistributedZkTest, TestRawResponseWriter, SOLR749Test, SpellCheckCollatorTest, TestWriterPerf, DocExpirationUpdateProcessorFactoryTest, DistribDocExpirationUpdateProcessorTest, TestSolr4Spatial2, VMParamsZkACLAndCredentialsProvidersTest, AssignTest, AsyncMigrateRouteKeyTest, PolyFieldTest, TestDefaultSimilarityFactory, OutOfBoxZkACLAndCredentialsProvidersTest, TestUniqueKeyFieldResource, TestSchemaVersionResource, DateFieldTest, ShardRoutingCustomTest, SampleTest, TestPostingsSolrHighlighter, HdfsWriteToMultipleCollectionsTest, TestFaceting, ZkNodePropsTest, DocumentAnalysisRequestHandlerTest, OverriddenZkACLAndCredentialsProvidersTest, TestStressReorder, TestBM25SimilarityFactory, TestDocumentBuilder, TestDistributedGrouping, TestSweetSpotSimilarityFactory, XsltUpdateRequestHandlerTest, TestDynamicFieldCollectionResource, RemoteQueryErrorTest, TestJmxMonitoredMap, ClusterStateTest, TestLMDirichletSimilarityFactory, TestDFRSimilarityFactory, TestConfigSets, TestLazyCores, PrimitiveFieldTypeTest, DocumentBuilderTest, TestPivotHelperCode, TestSolrQueryParserResource, SimpleMLTQParserTest, HighlighterTest, TestReload, SimplePostToolTest, AnalyticsQueryTest, TestDocSet, DateRangeFieldTest, BasicDistributedZkTest] [junit4] Completed in 72.72s, 1 test, 1 failure <<< FAILURES! [...truncated 814 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: 440 suites, 1800 tests, 1 failure, 53 ignored (30 assumptions) Total time: 178 minutes 22 seconds Build step 'Invoke Ant' marked build as failure [description-setter] Description set: Java: 32bit/jdk1.7.0_67 -server -XX:+UseConcMarkSweepGC Archiving artifacts Recording test results Email was triggered for: Failure - Any Sending email for trigger: Failure - Any
--------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
