Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/11347/ Java: 32bit/jdk1.9.0-ea-b28 -server -XX:+UseConcMarkSweepGC
1 tests failed. FAILED: org.apache.solr.cloud.HttpPartitionTest.testDistribSearch Error Message: Doc with id=2 not found in http://127.0.0.1:37774/nm_uc/c8n_1x2_leader_session_loss due to: Path not found: /id; rsp={doc=null} Stack Trace: java.lang.AssertionError: Doc with id=2 not found in http://127.0.0.1:37774/nm_uc/c8n_1x2_leader_session_loss due to: Path not found: /id; rsp={doc=null} at __randomizedtesting.SeedInfo.seed([FC05035FA51DFD06:7DE38D47D2429D3A]:0) at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.assertTrue(Assert.java:43) at org.apache.solr.cloud.HttpPartitionTest.assertDocExists(HttpPartitionTest.java:437) at org.apache.solr.cloud.HttpPartitionTest.testLeaderZkSessionLoss(HttpPartitionTest.java:324) at org.apache.solr.cloud.HttpPartitionTest.doTest(HttpPartitionTest.java:119) at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869) at sun.reflect.GeneratedMethodAccessor36.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:484) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836) at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738) at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) at java.lang.Thread.run(Thread.java:745) Build Log: [...truncated 11411 lines...] [junit4] Suite: org.apache.solr.cloud.HttpPartitionTest [junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/init-core-data-001 [junit4] 2> 1528641 T4099 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /nm_uc/ [junit4] 2> 1528643 T4099 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch [junit4] 2> 1528643 T4099 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1528644 T4100 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 1528744 T4099 oasc.ZkTestServer.run start zk server on port:47741 [junit4] 2> 1528744 T4099 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 1528745 T4099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1528747 T4106 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@155bac9 name:ZooKeeperConnection Watcher:127.0.0.1:47741 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1528747 T4099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1528748 T4099 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 1528748 T4099 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 1528752 T4099 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 1528753 T4099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1528755 T4108 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@186fe86 name:ZooKeeperConnection Watcher:127.0.0.1:47741/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1528755 T4099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1528755 T4099 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 1528756 T4099 oascc.SolrZkClient.makePath makePath: /collections/collection1 [junit4] 2> 1528760 T4099 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards [junit4] 2> 1528763 T4099 oascc.SolrZkClient.makePath makePath: /collections/control_collection [junit4] 2> 1528765 T4099 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards [junit4] 2> 1528768 T4099 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4] 2> 1528769 T4099 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml [junit4] 2> 1528772 T4099 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml [junit4] 2> 1528773 T4099 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml [junit4] 2> 1528776 T4099 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 1528777 T4099 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 1528780 T4099 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt [junit4] 2> 1528781 T4099 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt [junit4] 2> 1528783 T4099 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt [junit4] 2> 1528784 T4099 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt [junit4] 2> 1528786 T4099 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml [junit4] 2> 1528787 T4099 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml [junit4] 2> 1528789 T4099 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml [junit4] 2> 1528789 T4099 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml [junit4] 2> 1528792 T4099 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json [junit4] 2> 1528792 T4099 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json [junit4] 2> 1528795 T4099 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 1528795 T4099 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 1528798 T4099 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4] 2> 1528798 T4099 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt [junit4] 2> 1528800 T4099 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt [junit4] 2> 1528801 T4099 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt [junit4] 2> 1529049 T4099 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 1529053 T4099 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57876 [junit4] 2> 1529054 T4099 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 1529054 T4099 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 1529054 T4099 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-002 [junit4] 2> 1529055 T4099 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-002/' [junit4] 2> 1529065 T4099 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-002/solr.xml [junit4] 2> 1529079 T4099 oasc.CoreContainer.<init> New CoreContainer 82077 [junit4] 2> 1529080 T4099 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-002/] [junit4] 2> 1529081 T4099 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 1529081 T4099 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 1529081 T4099 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 1529082 T4099 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 1529082 T4099 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 1529083 T4099 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 1529083 T4099 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 1529083 T4099 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 1529084 T4099 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 1529084 T4099 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 1529085 T4099 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 1529085 T4099 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 1529086 T4099 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 1529086 T4099 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:47741/solr [junit4] 2> 1529087 T4099 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 1529087 T4099 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 1529088 T4099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1529090 T4119 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1fc8866 name:ZooKeeperConnection Watcher:127.0.0.1:47741 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1529090 T4099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1529091 T4099 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 1529094 T4099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1529094 T4121 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10c8991 name:ZooKeeperConnection Watcher:127.0.0.1:47741/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1529095 T4099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1529096 T4099 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 1529099 T4099 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 1529102 T4099 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 1529104 T4099 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 1529107 T4099 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 1529109 T4099 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 1529111 T4099 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51489_nm_uc [junit4] 2> 1529112 T4099 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51489_nm_uc [junit4] 2> 1529114 T4099 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 1529115 T4099 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 1529117 T4099 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 1529119 T4099 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:51489_nm_uc [junit4] 2> 1529119 T4099 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 1529122 T4099 oasc.Overseer.start Overseer (id=92535479001481219-127.0.0.1:51489_nm_uc-n_0000000000) starting [junit4] 2> 1529124 T4099 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 1529129 T4099 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 1529129 T4123 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 1529130 T4099 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 1529131 T4099 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 1529132 T4099 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 1529134 T4122 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 1529135 T4125 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection [junit4] 2> 1529135 T4125 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 1529136 T4125 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 1529136 T4126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1529137 T4122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "core":"collection1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:51489/nm_uc";, [junit4] 2> "node_name":"127.0.0.1:51489_nm_uc", [junit4] 2> "numShards":"1", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"control_collection", [junit4] 2> "operation":"state"} [junit4] 2> 1529138 T4122 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1] [junit4] 2> 1529138 T4122 oasc.Overseer$ClusterStateUpdater.createCollection state version control_collection 1 [junit4] 2> 1529138 T4122 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 1529139 T4126 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> 1530136 T4125 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 1530136 T4125 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection [junit4] 2> 1530137 T4125 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 1530137 T4125 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection [junit4] 2> 1530138 T4125 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper [junit4] 2> 1530139 T4125 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-002/collection1/' [junit4] 2> 1530140 T4125 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-002/collection1/lib/.svn/' to classloader [junit4] 2> 1530140 T4125 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-002/collection1/lib/classes/' to classloader [junit4] 2> 1530140 T4125 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-002/collection1/lib/README' to classloader [junit4] 2> 1530166 T4125 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0 [junit4] 2> 1530177 T4125 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 1530179 T4125 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml [junit4] 2> 1530184 T4125 oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 1530283 T4125 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 1530286 T4125 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 1530288 T4125 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 1530298 T4125 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 1530300 T4125 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 1530303 T4125 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 1530304 T4125 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 1530305 T4125 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 1530305 T4125 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 1530306 T4125 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 1530307 T4125 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 1530307 T4125 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection [junit4] 2> 1530307 T4125 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 1530307 T4125 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-002/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-001/control/data/ [junit4] 2> 1530308 T4125 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@156f0f2 [junit4] 2> 1530309 T4125 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-001/control/data [junit4] 2> 1530309 T4125 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-001/control/data/index/ [junit4] 2> 1530309 T4125 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-001/control/data/index' doesn't exist. Creating new index... [junit4] 2> 1530310 T4125 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-001/control/data/index [junit4] 2> 1530310 T4125 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=13.125, floorSegmentMB=1.197265625, forceMergeDeletesPctAllowed=7.335144323560813, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5195369018411685 [junit4] 2> 1530311 T4125 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-80ca7b)),segFN=segments_1,generation=1} [junit4] 2> 1530311 T4125 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 1530314 T4125 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 1530315 T4125 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 1530315 T4125 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 1530315 T4125 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 1530316 T4125 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 1530316 T4125 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 1530316 T4125 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 1530317 T4125 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 1530317 T4125 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 1530317 T4125 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 1530318 T4125 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 1530318 T4125 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 1530319 T4125 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 1530319 T4125 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 1530319 T4125 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 1530320 T4125 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 1530320 T4125 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 1530320 T4125 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 1530321 T4125 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 1530321 T4125 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 1530323 T4125 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 1530324 T4125 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 1530325 T4125 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 1530326 T4125 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 1530328 T4125 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 1530328 T4125 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 1530329 T4125 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=39, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=32.349609375, floorSegmentMB=2.0556640625, forceMergeDeletesPctAllowed=24.71840644636208, segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.723183819425404 [junit4] 2> 1530329 T4125 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-80ca7b)),segFN=segments_1,generation=1} [junit4] 2> 1530329 T4125 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 1530330 T4125 oass.SolrIndexSearcher.<init> Opening Searcher@1e15487[collection1] main [junit4] 2> 1530330 T4125 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection [junit4] 2> 1530331 T4125 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper [junit4] 2> 1530331 T4125 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 1530331 T4125 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 1530332 T4125 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 1530332 T4125 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 1530333 T4125 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json [junit4] 2> 1530333 T4125 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 1530333 T4125 oascc.SolrZkClient.makePath makePath: /configs/conf1/_rest_managed.json [junit4] 2> 1530336 T4125 oasr.ManagedResourceStorage$ZooKeeperStorageIO$1.close Wrote 38 bytes to new znode /configs/conf1/_rest_managed.json [junit4] 2> 1530336 T4125 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 1530336 T4125 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 1530338 T4128 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1e15487[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 1530339 T4125 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 1530339 T4131 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51489/nm_uc collection:control_collection shard:shard1 [junit4] 2> 1530340 T4099 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1 [junit4] 2> 1530341 T4099 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 1530340 T4131 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election [junit4] 2> 1530342 T4099 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 1530343 T4099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1530344 T4134 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11ebb0a name:ZooKeeperConnection Watcher:127.0.0.1:47741/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1530344 T4099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1530344 T4099 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 1530345 T4131 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1 [junit4] 2> 1530345 T4099 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 1530346 T4126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1530346 T4131 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue. [junit4] 2> 1530347 T4131 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync [junit4] 2> ASYNC NEW_CORE C4356 name=collection1 org.apache.solr.core.SolrCore@1e348b3 url=http://127.0.0.1:51489/nm_uc/collection1 node=127.0.0.1:51489_nm_uc C4356_STATE=coll:control_collection core:collection1 props:{core=collection1, base_url=http://127.0.0.1:51489/nm_uc, node_name=127.0.0.1:51489_nm_uc, state=down} [junit4] 2> 1530347 T4131 C4356 P51489 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51489/nm_uc/collection1/ [junit4] 2> 1530347 T4131 C4356 P51489 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me [junit4] 2> 1530347 T4131 C4356 P51489 oasc.SyncStrategy.syncToMe http://127.0.0.1:51489/nm_uc/collection1/ has no replicas [junit4] 2> 1530347 T4099 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false [junit4] 2> 1530347 T4131 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51489/nm_uc/collection1/ shard1 [junit4] 2> 1530348 T4099 oasc.AbstractFullDistribZkTestBase.createJettys Creating collection1 with stateFormat=2 [junit4] 2> 1530348 T4099 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 1530349 T4131 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1 [junit4] 2> 1530349 T4099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1530349 T4136 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f3e179 name:ZooKeeperConnection Watcher:127.0.0.1:47741/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1530349 T4099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1530350 T4099 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 1530351 T4126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1530352 T4122 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: collection1 [junit4] 2> 1530352 T4122 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2] [junit4] 2> 1530352 T4122 oasc.Overseer$ClusterStateUpdater.createCollection state version collection1 2 [junit4] 2> 1530354 T4122 oasc.Overseer$ClusterStateUpdater.updateZkStates going to create_collection /collections/collection1/state.json [junit4] 2> 1530354 T4126 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> 1530355 T4137 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> 1530360 T4126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1530361 T4126 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> 1530361 T4137 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> 1530402 T4131 oasc.ZkController.register We are http://127.0.0.1:51489/nm_uc/collection1/ and leader is http://127.0.0.1:51489/nm_uc/collection1/ [junit4] 2> 1530403 T4131 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51489/nm_uc [junit4] 2> 1530403 T4131 oasc.ZkController.checkRecovery I am the leader, no recovery necessary [junit4] 2> 1530403 T4131 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection [junit4] 2> 1530403 T4131 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 1530404 T4126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1530406 T4122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "core":"collection1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:51489/nm_uc";, [junit4] 2> "node_name":"127.0.0.1:51489_nm_uc", [junit4] 2> "numShards":"2", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"control_collection", [junit4] 2> "operation":"state"} [junit4] 2> 1530508 T4137 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> 1530508 T4126 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> 1530626 T4099 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1 [junit4] 2> 1530627 T4099 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 1530628 T4099 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:43740 [junit4] 2> 1530629 T4099 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 1530629 T4099 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 1530630 T4099 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-003 [junit4] 2> 1530630 T4099 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-003/' [junit4] 2> 1530639 T4099 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-003/solr.xml [junit4] 2> 1530645 T4099 oasc.CoreContainer.<init> New CoreContainer 16404508 [junit4] 2> 1530646 T4099 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-003/] [junit4] 2> 1530646 T4099 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 1530646 T4099 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 1530647 T4099 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 1530647 T4099 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 1530647 T4099 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 1530648 T4099 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 1530648 T4099 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 1530648 T4099 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 1530648 T4099 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 1530649 T4099 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 1530649 T4099 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 1530649 T4099 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 1530650 T4099 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 1530650 T4099 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:47741/solr [junit4] 2> 1530650 T4099 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 1530650 T4099 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 1530651 T4099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1530652 T4148 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@52562b name:ZooKeeperConnection Watcher:127.0.0.1:47741 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1530653 T4099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1530653 T4099 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 1530655 T4099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1530656 T4150 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a1f60e name:ZooKeeperConnection Watcher:127.0.0.1:47741/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1530656 T4099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1530662 T4099 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 1531665 T4099 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51844_nm_uc [junit4] 2> 1531667 T4099 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51844_nm_uc [junit4] 2> 1531671 T4099 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 1531677 T4152 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1 [junit4] 2> 1531678 T4152 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 1531679 T4126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1531680 T4152 oasc.ZkController.preRegister Registering watch for external collection collection1 [junit4] 2> 1531680 T4152 oascc.ZkStateReader.addZkWatch addZkWatch collection1 [junit4] 2> 1531681 T4152 oascc.ZkStateReader.addZkWatch Updating collection state at /collections/collection1/state.json from ZooKeeper... [junit4] 2> 1531682 T4122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "core":"collection1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:51844/nm_uc";, [junit4] 2> "node_name":"127.0.0.1:51844_nm_uc", [junit4] 2> "numShards":"2", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 1531683 T4152 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 0 [junit4] 2> 1531683 T4152 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 1531686 T4122 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2 [junit4] 2> 1531687 T4122 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2 [junit4] 2> 1531692 T4122 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json [junit4] 2> 1531693 T4151 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 1531693 T4151 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 1 [junit4] 2> 1532684 T4152 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 1532684 T4152 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1 [junit4] 2> 1532684 T4152 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 1532685 T4152 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 1532686 T4152 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 1532686 T4152 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-003/collection1/' [junit4] 2> 1532686 T4152 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-003/collection1/lib/.svn/' to classloader [junit4] 2> 1532686 T4152 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-003/collection1/lib/classes/' to classloader [junit4] 2> 1532687 T4152 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-003/collection1/lib/README' to classloader [junit4] 2> 1532707 T4152 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0 [junit4] 2> 1532722 T4152 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 1532722 T4152 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml [junit4] 2> 1532727 T4152 oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 1532813 T4152 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 1532816 T4152 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 1532817 T4152 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 1532825 T4152 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 1532826 T4152 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 1532827 T4152 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 1532828 T4152 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 1532829 T4152 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 1532829 T4152 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 1532830 T4152 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 1532830 T4152 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 1532830 T4152 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 1532830 T4152 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 1532831 T4152 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-003/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-001/jetty1/ [junit4] 2> 1532831 T4152 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@156f0f2 [junit4] 2> 1532831 T4152 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-001/jetty1 [junit4] 2> 1532831 T4152 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-001/jetty1/index/ [junit4] 2> 1532832 T4152 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-001/jetty1/index' doesn't exist. Creating new index... [junit4] 2> 1532832 T4152 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-001/jetty1/index [junit4] 2> 1532832 T4152 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=13.125, floorSegmentMB=1.197265625, forceMergeDeletesPctAllowed=7.335144323560813, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5195369018411685 [junit4] 2> 1532833 T4152 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1bafc29)),segFN=segments_1,generation=1} [junit4] 2> 1532833 T4152 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 1532836 T4152 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 1532836 T4152 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 1532836 T4152 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 1532836 T4152 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 1532837 T4152 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 1532837 T4152 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 1532837 T4152 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 1532837 T4152 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 1532838 T4152 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 1532838 T4152 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 1532841 T4152 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 1532842 T4152 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 1532842 T4152 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 1532842 T4152 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 1532843 T4152 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 1532843 T4152 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 1532843 T4152 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 1532843 T4152 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 1532844 T4152 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 1532844 T4152 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 1532845 T4152 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 1532846 T4152 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 1532846 T4152 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 1532847 T4152 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 1532848 T4152 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 1532848 T4152 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 1532849 T4152 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=39, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=32.349609375, floorSegmentMB=2.0556640625, forceMergeDeletesPctAllowed=24.71840644636208, segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.723183819425404 [junit4] 2> 1532849 T4152 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1bafc29)),segFN=segments_1,generation=1} [junit4] 2> 1532849 T4152 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 1532849 T4152 oass.SolrIndexSearcher.<init> Opening Searcher@1439054[collection1] main [junit4] 2> 1532850 T4152 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 1532850 T4152 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 1532851 T4152 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 1532851 T4152 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 1532851 T4152 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 1532851 T4152 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 1532852 T4152 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json [junit4] 2> 1532852 T4152 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 1532852 T4152 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed [junit4] 2> 1532853 T4152 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 1532854 T4153 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1439054[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 1532856 T4152 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 1532856 T4156 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51844/nm_uc collection:collection1 shard:shard2 [junit4] 2> 1532857 T4099 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1 [junit4] 2> 1532857 T4156 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election [junit4] 2> 1532857 T4099 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 1532861 T4156 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2 [junit4] 2> 1532862 T4156 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue. [junit4] 2> 1532862 T4156 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync [junit4] 2> ASYNC NEW_CORE C4357 name=collection1 org.apache.solr.core.SolrCore@7dc875 url=http://127.0.0.1:51844/nm_uc/collection1 node=127.0.0.1:51844_nm_uc C4357_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:51844/nm_uc, node_name=127.0.0.1:51844_nm_uc, state=down} [junit4] 2> 1532862 T4156 C4357 P51844 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51844/nm_uc/collection1/ [junit4] 2> 1532863 T4156 C4357 P51844 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me [junit4] 2> 1532863 T4156 C4357 P51844 oasc.SyncStrategy.syncToMe http://127.0.0.1:51844/nm_uc/collection1/ has no replicas [junit4] 2> 1532863 T4156 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51844/nm_uc/collection1/ shard2 [junit4] 2> 1532863 T4156 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2 [junit4] 2> 1532864 T4126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1532868 T4122 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json [junit4] 2> 1532869 T4151 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 1532869 T4151 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 2 [junit4] 2> 1532879 T4126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1532879 T4122 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json [junit4] 2> 1532879 T4151 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 1532880 T4151 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 3 [junit4] 2> 1532917 T4156 oasc.ZkController.register We are http://127.0.0.1:51844/nm_uc/collection1/ and leader is http://127.0.0.1:51844/nm_uc/collection1/ [junit4] 2> 1532917 T4156 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51844/nm_uc [junit4] 2> 1532917 T4156 oasc.ZkController.checkRecovery I am the leader, no recovery necessary [junit4] 2> 1532917 T4156 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1 [junit4] 2> 1532917 T4156 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 1532918 T4126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1532920 T4156 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 3 [junit4] 2> 1532920 T4122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "core":"collection1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:51844/nm_uc";, [junit4] 2> "node_name":"127.0.0.1:51844_nm_uc", [junit4] 2> "numShards":"2", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard2", [junit4] 2> "collection":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 1532922 T4122 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json [junit4] 2> 1532923 T4151 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 1532923 T4151 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 4 [junit4] 2> 1533105 T4099 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2 [junit4] 2> 1533106 T4099 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 1533107 T4099 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:32973 [junit4] 2> 1533108 T4099 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 1533109 T4099 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 1533109 T4099 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-004 [junit4] 2> 1533109 T4099 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-004/' [junit4] 2> 1533119 T4099 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-004/solr.xml [junit4] 2> 1533125 T4099 oasc.CoreContainer.<init> New CoreContainer 24755784 [junit4] 2> 1533125 T4099 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-004/] [junit4] 2> 1533126 T4099 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 1533126 T4099 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 1533126 T4099 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 1533127 T4099 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 1533127 T4099 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 1533127 T4099 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 1533127 T4099 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 1533128 T4099 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 1533128 T4099 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 1533128 T4099 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 1533129 T4099 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 1533129 T4099 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 1533129 T4099 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 1533129 T4099 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:47741/solr [junit4] 2> 1533130 T4099 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 1533130 T4099 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 1533131 T4099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1533131 T4168 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16493e9 name:ZooKeeperConnection Watcher:127.0.0.1:47741 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1533132 T4099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1533132 T4099 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 1533134 T4099 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 1533134 T4170 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f1e78 name:ZooKeeperConnection Watcher:127.0.0.1:47741/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1533134 T4099 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 1533137 T4099 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 1534141 T4099 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39061_nm_uc [junit4] 2> 1534142 T4099 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39061_nm_uc [junit4] 2> 1534148 T4099 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 1534156 T4172 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1 [junit4] 2> 1534156 T4172 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 1534158 T4126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1534159 T4172 oasc.ZkController.preRegister Registering watch for external collection collection1 [junit4] 2> 1534160 T4172 oascc.ZkStateReader.addZkWatch addZkWatch collection1 [junit4] 2> 1534160 T4172 oascc.ZkStateReader.addZkWatch Updating collection state at /collections/collection1/state.json from ZooKeeper... [junit4] 2> 1534162 T4122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "core":"collection1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:39061/nm_uc";, [junit4] 2> "node_name":"127.0.0.1:39061_nm_uc", [junit4] 2> "numShards":"2", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 1534162 T4172 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 4 [junit4] 2> 1534163 T4172 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 1534166 T4122 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2 [junit4] 2> 1534167 T4122 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 1534173 T4122 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json [junit4] 2> 1534174 T4151 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 1534174 T4171 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 1534175 T4151 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 5 [junit4] 2> 1534175 T4171 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 5 [junit4] 2> 1535163 T4172 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1 [junit4] 2> 1535164 T4172 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1 [junit4] 2> 1535164 T4172 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 1535165 T4172 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 1535166 T4172 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 1535166 T4172 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-004/collection1/' [junit4] 2> 1535167 T4172 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-004/collection1/lib/.svn/' to classloader [junit4] 2> 1535168 T4172 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-004/collection1/lib/classes/' to classloader [junit4] 2> 1535168 T4172 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-004/collection1/lib/README' to classloader [junit4] 2> 1535205 T4172 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0 [junit4] 2> 1535214 T4172 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 1535215 T4172 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml [junit4] 2> 1535219 T4172 oass.IndexSchema.readSchema [collection1] Schema name=test [junit4] 2> 1535307 T4172 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 1535311 T4172 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 1535312 T4172 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 1535321 T4172 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 1535322 T4172 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 1535324 T4172 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 1535324 T4172 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 1535325 T4172 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 1535326 T4172 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 1535326 T4172 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 1535327 T4172 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 1535327 T4172 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 1535327 T4172 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 1535327 T4172 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-004/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-001/jetty2/ [junit4] 2> 1535328 T4172 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@156f0f2 [junit4] 2> 1535328 T4172 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-001/jetty2 [junit4] 2> 1535328 T4172 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-001/jetty2/index/ [junit4] 2> 1535328 T4172 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-001/jetty2/index' doesn't exist. Creating new index... [junit4] 2> 1535329 T4172 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-001/jetty2/index [junit4] 2> 1535329 T4172 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=13.125, floorSegmentMB=1.197265625, forceMergeDeletesPctAllowed=7.335144323560813, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5195369018411685 [junit4] 2> 1535329 T4172 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-584af7)),segFN=segments_1,generation=1} [junit4] 2> 1535330 T4172 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 1535332 T4172 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 1535332 T4172 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 1535332 T4172 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 1535333 T4172 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 1535333 T4172 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 1535333 T4172 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 1535333 T4172 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 1535333 T4172 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 1535334 T4172 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 1535334 T4172 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 1535334 T4172 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 1535335 T4172 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 1535335 T4172 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 1535335 T4172 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 1535335 T4172 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 1535336 T4172 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 1535336 T4172 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 1535336 T4172 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 1535337 T4172 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 1535337 T4172 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 1535339 T4172 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 1535339 T4172 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 1535340 T4172 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 1535341 T4172 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 1535342 T4172 oasu.CommitTracker.<init> Hard AutoCommit: disabled [junit4] 2> 1535342 T4172 oasu.CommitTracker.<init> Soft AutoCommit: disabled [junit4] 2> 1535342 T4172 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=39, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=32.349609375, floorSegmentMB=2.0556640625, forceMergeDeletesPctAllowed=24.71840644636208, segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.723183819425404 [junit4] 2> 1535343 T4172 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1 [junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-584af7)),segFN=segments_1,generation=1} [junit4] 2> 1535343 T4172 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 1535343 T4172 oass.SolrIndexSearcher.<init> Opening Searcher@4165d[collection1] main [junit4] 2> 1535343 T4172 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1 [junit4] 2> 1535344 T4172 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper [junit4] 2> 1535344 T4172 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 1535345 T4172 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 1535345 T4172 oasr.RestManager.init Initializing RestManager with initArgs: {} [junit4] 2> 1535345 T4172 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 1535346 T4172 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json [junit4] 2> 1535346 T4172 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 1535346 T4172 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed [junit4] 2> 1535346 T4172 oasr.RestManager.init Initializing 0 registered ManagedResources [junit4] 2> 1535348 T4173 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4165d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 1535350 T4172 oasc.CoreContainer.registerCore registering core: collection1 [junit4] 2> 1535350 T4176 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:39061/nm_uc collection:collection1 shard:shard1 [junit4] 2> 1535351 T4099 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1 [junit4] 2> 1535351 T4099 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 1535351 T4176 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 1535355 T4176 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1 [junit4] 2> 1535356 T4126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1535356 T4176 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue. [junit4] 2> 1535356 T4176 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync [junit4] 2> ASYNC NEW_CORE C4358 name=collection1 org.apache.solr.core.SolrCore@3d9a9d url=http://127.0.0.1:39061/nm_uc/collection1 node=127.0.0.1:39061_nm_uc C4358_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:39061/nm_uc, node_name=127.0.0.1:39061_nm_uc, state=down} [junit4] 2> 1535356 T4176 C4358 P39061 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:39061/nm_uc/collection1/ [junit4] 2> 1535356 T4176 C4358 P39061 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me [junit4] 2> 1535357 T4176 C4358 P39061 oasc.SyncStrategy.syncToMe http://127.0.0.1:39061/nm_uc/collection1/ has no replicas [junit4] 2> 1535357 T4176 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:39061/nm_uc/collection1/ shard1 [junit4] 2> 1535357 T4176 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1535359 T4122 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json [junit4] 2> 1535359 T4151 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 1535359 T4151 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 6 [junit4] 2> 1535366 T4171 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 1535366 T4126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1535366 T4171 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 6 [junit4] 2> 1535369 T4122 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json [junit4] 2> 1535369 T4151 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 1535369 T4171 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 1535370 T4151 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 7 [junit4] 2> 1535370 T4171 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 7 [junit4] 2> 1535417 T4176 oasc.ZkController.register We are http://127.0.0.1:39061/nm_uc/collection1/ and leader is http://127.0.0.1:39061/nm_uc/collection1/ [junit4] 2> 1535417 T4176 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39061/nm_uc [junit4] 2> 1535417 T4176 oasc.ZkController.checkRecovery I am the leader, no recovery necessary [junit4] 2> 1535417 T4176 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1 [junit4] 2> 1535418 T4176 oasc.ZkController.publish numShards not found on descriptor - reading it from system property [junit4] 2> 1535419 T4126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 1535420 T4176 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 7 [junit4] 2> 1535420 T4122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "core":"collection1", [junit4] 2> "core_node_name":"core_node2", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:39061/nm_uc";, [junit4] 2> "node_name":"127.0.0.1:39061_nm_uc", [junit4] 2> "numShards":"2", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 1535423 T4122 oasc.Overseer$ClusterStateUpdater.updateZkStates going to update_collection /collections/collection1/state.json [junit4] 2> 1535423 T4151 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 1535423 T4171 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 1535423 T4151 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 8 [junit4] 2> 1535424 T4171 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 8 [junit4] 2> 1535605 T4099 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3 [junit4] 2> 1535605 T4099 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 1535607 T4099 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54932 [junit4] 2> 1535608 T4099 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 1535608 T4099 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 1535608 T4099 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-005 [junit4] 2> 1535609 T4099 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-005/' [junit4] 2> 1535618 T4099 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-005/solr.xml [junit4] 2> 1535641 T4099 oasc.CoreContainer.<init> New CoreContainer 19437711 [junit4] 2> 1535642 T4099 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001/tempDir-005/] [junit4] 2> 1535642 T4099 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000 [junit4] 2> 1535643 T4099 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: [junit4] 2> 1535643 T4099 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 1535643 T4099 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 1535644 T4099 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 1535644 T4099 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 1535644 T4099 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 1535645 T4099 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 1535645 T4099 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 1535646 T4099 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false [junit4] 2> 1535646 T4099 oasl.LogWatcher.createWatcher SLF4J impl [...truncated too long message...] va:520) [junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.updateClusterState(ZkStateReader.java:253) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:277) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> Caused by: java.lang.InterruptedException [junit4] 2> at java.lang.Object.wait(Native Method) [junit4] 2> at java.lang.Object.wait(Object.java:502) [junit4] 2> at org.apache.zookeeper.ClientCnxn.submitRequest(ClientCnxn.java:1342) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1153) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:347) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:344) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:344) [junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.getCollectionLive(ZkStateReader.java:761) [junit4] 2> ... 4 more [junit4] 2> [junit4] 2> 1630989 T4455 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:37774_nm_uc [junit4] 2> 1630989 T4418 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK [junit4] 2> 1630989 T4191 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK [junit4] 2> 1631017 T4099 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/nm_uc,null} [junit4] 2> 1636005 T4099 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch [junit4] 2> 1636007 T4099 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:47741 47741 [junit4] 2> 1636554 T4100 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:47741 47741 [junit4] 2> 1636556 T4100 oasc.ZkTestServer$ZKServerMain.runFromConfig WARN Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 6 /solr/aliases.json [junit4] 2> 6 /solr/clusterstate.json [junit4] 2> 4 /solr/collections/collection1/state.json [junit4] 2> 3 /solr/collections/c8n_1x3/state.json [junit4] 2> 3 /solr/collections/c8n_1x2_leader_session_loss/state.json [junit4] 2> 2 /solr/collections/c8n_1x2/state.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 2 /solr/overseer_elect/election/92535479001481225-127.0.0.1:39061_nm_uc-n_0000000002 [junit4] 2> 2 /solr/collections/collection1/leader_elect/shard2/election/92535479001481223-core_node1-n_0000000000 [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 7 /solr/live_nodes [junit4] 2> 4 /solr/overseer/queue [junit4] 2> 4 /solr/overseer/collection-queue-work [junit4] 2> [junit4] 2> 1636556 T4099 oasc.SocketProxy.close WARN Closing 0 connections to: http://127.0.0.1:51489/nm_uc [junit4] 2> 1636557 T4099 oasc.SocketProxy.close WARN Closing 0 connections to: http://127.0.0.1:39061/nm_uc [junit4] 2> 1636558 T4099 oasc.SocketProxy.close WARN Closing 0 connections to: http://127.0.0.1:37774/nm_uc [junit4] 2> 1636558 T4099 oasc.SocketProxy.close WARN Closing 0 connections to: http://127.0.0.1:51844/nm_uc [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=HttpPartitionTest -Dtests.method=testDistribSearch -Dtests.seed=FC05035FA51DFD06 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=cs_CZ -Dtests.timezone=Chile/EasterIsland -Dtests.file.encoding=ISO-8859-1 [junit4] FAILURE 108s J1 | HttpPartitionTest.testDistribSearch <<< [junit4] > Throwable #1: java.lang.AssertionError: Doc with id=2 not found in http://127.0.0.1:37774/nm_uc/c8n_1x2_leader_session_loss due to: Path not found: /id; rsp={doc=null} [junit4] > at __randomizedtesting.SeedInfo.seed([FC05035FA51DFD06:7DE38D47D2429D3A]:0) [junit4] > at org.apache.solr.cloud.HttpPartitionTest.assertDocExists(HttpPartitionTest.java:437) [junit4] > at org.apache.solr.cloud.HttpPartitionTest.testLeaderZkSessionLoss(HttpPartitionTest.java:324) [junit4] > at org.apache.solr.cloud.HttpPartitionTest.doTest(HttpPartitionTest.java:119) [junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869) [junit4] > at java.lang.Thread.run(Thread.java:745) [junit4] 2> 1636574 T4099 oas.SolrTestCaseJ4.deleteCore ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest-FC05035FA51DFD06-001 [junit4] 2> 107942 T4098 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s). [junit4] 2> NOTE: test params are: codec=Asserting(Lucene50): {_version_=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene41(blocksize=128))), multiDefault=PostingsFormat(name=Asserting), a_t=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene41(blocksize=128))), intDefault=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene41(blocksize=128))), id=PostingsFormat(name=Memory doPackFST= true), text=FSTOrd41, range_facet_l=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene41(blocksize=128))), timestamp=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene41(blocksize=128)))}, docValues:{timestamp=DocValuesFormat(name=SimpleText)}, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=cs_CZ, timezone=Chile/EasterIsland [junit4] 2> NOTE: Linux 3.13.0-36-generic i386/Oracle Corporation 1.9.0-ea (32-bit)/cpus=8,threads=1,free=157439888,total=395538432 [junit4] 2> NOTE: All tests run in this JVM: [StatsComponentTest, DateFieldTest, TestJoin, LoggingHandlerTest, DeleteInactiveReplicaTest, TestManagedResourceStorage, RAMDirectoryFactoryTest, TestSolr4Spatial2, TestCloudSchemaless, TermVectorComponentTest, TestFieldSortValues, URLClassifyProcessorTest, TestPivotHelperCode, SolrXmlInZkTest, ChaosMonkeySafeLeaderTest, TestLazyCores, TestWriterPerf, ParsingFieldUpdateProcessorsTest, DeleteShardTest, TestMultiCoreConfBootstrap, TestAnalyzeInfixSuggestions, DistanceFunctionTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestElisionMultitermQuery, OverriddenZkACLAndCredentialsProvidersTest, TestOmitPositions, IndexSchemaRuntimeFieldTest, AnalyticsMergeStrategyTest, HardAutoCommitTest, SortByFunctionTest, TestNRTOpen, FileBasedSpellCheckerTest, TestAddFieldRealTimeGet, TestCloudManagedSchemaConcurrent, TestInitQParser, BlockDirectoryTest, TestUtils, CircularListTest, CoreAdminCreateDiscoverTest, PrimUtilsTest, DocValuesTest, TestPerFieldSimilarity, TestCollectionAPI, TestJmxMonitoredMap, TestExtendedDismaxParser, SolrCoreTest, TestSearcherReuse, TestCSVResponseWriter, FullSolrCloudDistribCmdsTest, PreAnalyzedFieldTest, BasicDistributedZk2Test, SpatialFilterTest, CoreAdminRequestStatusTest, TestIndexingPerformance, TestRecovery, TestSchemaNameResource, TestSolrQueryParser, ReplicationFactorTest, TestStressLucene, ClusterStateTest, TestQueryTypes, TestPHPSerializedResponseWriter, TestBinaryField, TestStandardQParsers, MergeStrategyTest, TestSolrXml, DirectSolrConnectionTest, SchemaVersionSpecificBehaviorTest, DistributedQueryElevationComponentTest, TestChildDocTransformer, DistributedTermsComponentTest, TestImplicitCoreProperties, ExitableDirectoryReaderTest, LeaderFailoverAfterPartitionTest, TestFunctionQuery, FieldAnalysisRequestHandlerTest, UpdateRequestProcessorFactoryTest, SolrInfoMBeanTest, TestHighFrequencyDictionaryFactory, SharedFSAutoReplicaFailoverUtilsTest, DistributedIntervalFacetingTest, QueryParsingTest, HdfsLockFactoryTest, OpenCloseCoreStressTest, TestCollationField, LukeRequestHandlerTest, DistributedQueryComponentOptimizationTest, BJQParserTest, TestReplicationHandlerBackup, SuggestComponentTest, TestCloudManagedSchema, TestManagedSchemaDynamicFieldResource, CSVRequestHandlerTest, BinaryUpdateRequestHandlerTest, TestDefaultSearchFieldResource, TestHighlightDedupGrouping, TestDistributedGrouping, AliasIntegrationTest, CopyFieldTest, SolrTestCaseJ4Test, BasicZkTest, DateMathParserTest, CoreMergeIndexesAdminHandlerTest, HttpPartitionTest] [junit4] Completed on J1 in 108.23s, 1 test, 1 failure <<< FAILURES! [...truncated 674 lines...] BUILD FAILED /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:524: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:472: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:61: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:39: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:496: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1359: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:961: There were test failures: 432 suites, 1778 tests, 1 failure, 44 ignored (22 assumptions) Total time: 98 minutes 8 seconds Build step 'Invoke Ant' marked build as failure [description-setter] Description set: Java: 32bit/jdk1.9.0-ea-b28 -server -XX:+UseConcMarkSweepGC Archiving artifacts Recording test results Email was triggered for: Failure - Any Sending email for trigger: Failure - Any
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org
