You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/02/01 12:00:45 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.7.0_51) - Build # 9215
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9215/
Java: 64bit/jdk1.7.0_51 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.testDistribSearch
Error Message:
collection already exists: collection2
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: collection already exists: collection2
at __randomizedtesting.SeedInfo.seed([1A968975EBCB6FEC:9B70076D9C940FD0]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:495)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:283)
at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:640)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1623)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1649)
at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.testIndexingBatchPerRequestWithHttpSolrServer(FullSolrCloudDistribCmdsTest.java:353)
at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.doTest(FullSolrCloudDistribCmdsTest.java:143)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:867)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:744)
Build Log:
[...truncated 10597 lines...]
[junit4] Suite: org.apache.solr.cloud.FullSolrCloudDistribCmdsTest
[junit4] 2> 776600 T4265 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /vb_j/b
[junit4] 2> 776604 T4265 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-FullSolrCloudDistribCmdsTest-1391251707446
[junit4] 2> 776604 T4265 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 776605 T4266 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 776705 T4265 oasc.ZkTestServer.run start zk server on port:36436
[junit4] 2> 776706 T4265 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 776984 T4272 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e969743 name:ZooKeeperConnection Watcher:127.0.0.1:36436 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 776984 T4265 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 776984 T4265 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 776989 T4265 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 776990 T4274 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50edeb06 name:ZooKeeperConnection Watcher:127.0.0.1:36436/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 776990 T4265 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 776990 T4265 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 776994 T4265 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 776997 T4265 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 776999 T4265 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 777001 T4265 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 777001 T4265 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 777004 T4265 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 777004 T4265 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 777006 T4265 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 777007 T4265 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 777009 T4265 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 777009 T4265 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 777011 T4265 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 777012 T4265 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 777013 T4265 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 777014 T4265 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 777015 T4265 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 777016 T4265 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 777018 T4265 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 777018 T4265 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 777020 T4265 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 777020 T4265 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 777022 T4265 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 777022 T4265 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 777024 T4265 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 777025 T4265 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 777095 T4265 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 777098 T4265 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:56039
[junit4] 2> 777099 T4265 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 777099 T4265 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 777099 T4265 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1391251707869
[junit4] 2> 777100 T4265 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1391251707869/'
[junit4] 2> 777114 T4265 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1391251707869/solr.xml
[junit4] 2> 777157 T4265 oasc.CoreContainer.<init> New CoreContainer 2045320784
[junit4] 2> 777157 T4265 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1391251707869/]
[junit4] 2> 777158 T4265 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 777158 T4265 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 777158 T4265 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 777159 T4265 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 777159 T4265 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 777159 T4265 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 777159 T4265 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 777160 T4265 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 777160 T4265 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 777162 T4265 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 777162 T4265 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 777162 T4265 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 777163 T4265 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36436/solr
[junit4] 2> 777163 T4265 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 777164 T4265 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 777166 T4285 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@37c554b7 name:ZooKeeperConnection Watcher:127.0.0.1:36436 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 777166 T4265 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 777167 T4265 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 777169 T4287 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2d53dce1 name:ZooKeeperConnection Watcher:127.0.0.1:36436/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 777169 T4265 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 777170 T4265 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 777179 T4265 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 777182 T4265 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 777183 T4265 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56039_vb_j%2Fb
[junit4] 2> 777183 T4265 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56039_vb_j%2Fb
[junit4] 2> 777185 T4265 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 777187 T4265 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 777189 T4265 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:56039_vb_j%2Fb
[junit4] 2> 777190 T4265 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 777191 T4265 oasc.Overseer.start Overseer (id=91177071899312131-127.0.0.1:56039_vb_j%2Fb-n_0000000000) starting
[junit4] 2> 777193 T4265 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 777195 T4289 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 777196 T4265 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 777196 T4289 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 777197 T4265 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 777198 T4265 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 777200 T4288 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 777203 T4290 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 777203 T4290 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 777206 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 777206 T4290 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 777208 T4288 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 777208 T4288 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:56039/vb_j/b",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:56039_vb_j%2Fb",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 777209 T4288 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 777209 T4288 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 777211 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 777211 T4287 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> 778207 T4290 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 778207 T4290 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1391251707869/collection1
[junit4] 2> 778207 T4290 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 778208 T4290 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 778208 T4290 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 778209 T4290 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1391251707869/collection1/'
[junit4] 2> 778210 T4290 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1391251707869/collection1/lib/classes/' to classloader
[junit4] 2> 778210 T4290 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1391251707869/collection1/lib/README' to classloader
[junit4] 2> 778248 T4290 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 778300 T4290 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 778301 T4290 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 778307 T4290 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 778735 T4290 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 778737 T4290 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 778738 T4290 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 778741 T4290 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 778759 T4290 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 778759 T4290 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1391251707869/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/control/data/
[junit4] 2> 778759 T4290 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3f42f573
[junit4] 2> 778760 T4290 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/control/data
[junit4] 2> 778760 T4290 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/control/data/index/
[junit4] 2> 778760 T4290 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 778761 T4290 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/control/data/index
[junit4] 2> 778761 T4290 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=3.0537109375, floorSegmentMB=1.28125, forceMergeDeletesPctAllowed=15.707759260704117, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.20257078227297934
[junit4] 2> 778762 T4290 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@6844a2ba lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@614200a3),segFN=segments_1,generation=1}
[junit4] 2> 778762 T4290 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 778764 T4290 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 778765 T4290 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 778765 T4290 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 778765 T4290 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 778765 T4290 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 778765 T4290 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 778766 T4290 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 778766 T4290 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 778766 T4290 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 778767 T4290 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 778767 T4290 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 778767 T4290 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 778767 T4290 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 778768 T4290 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 778768 T4290 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 778768 T4290 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 778770 T4290 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 778774 T4290 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 778774 T4290 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 778775 T4290 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=15, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 778775 T4290 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@6844a2ba lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@614200a3),segFN=segments_1,generation=1}
[junit4] 2> 778775 T4290 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 778776 T4290 oass.SolrIndexSearcher.<init> Opening Searcher@6a0fd270 main
[junit4] 2> 778778 T4291 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6a0fd270 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 778779 T4290 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 778780 T4265 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 778780 T4265 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 778780 T4294 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56039/vb_j/b collection:control_collection shard:shard1
[junit4] 2> 778781 T4265 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 778782 T4294 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 778784 T4296 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ca43a38 name:ZooKeeperConnection Watcher:127.0.0.1:36436/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 778785 T4265 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 778786 T4265 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 778788 T4294 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 778788 T4265 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 778791 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 778791 T4294 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 778792 T4294 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C2084 name=collection1 org.apache.solr.core.SolrCore@2a95e154 url=http://127.0.0.1:56039/vb_j/b/collection1 node=127.0.0.1:56039_vb_j%2Fb C2084_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:56039/vb_j/b, core=collection1, node_name=127.0.0.1:56039_vb_j%2Fb}
[junit4] 2> 778792 T4294 C2084 P56039 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:56039/vb_j/b/collection1/
[junit4] 2> 778792 T4294 C2084 P56039 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 778792 T4294 C2084 P56039 oasc.SyncStrategy.syncToMe http://127.0.0.1:56039/vb_j/b/collection1/ has no replicas
[junit4] 2> 778792 T4288 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 778792 T4294 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:56039/vb_j/b/collection1/ shard1
[junit4] 2> 778793 T4294 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 778795 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 778796 T4287 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> 778798 T4296 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> 778801 T4288 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 778806 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 778856 T4265 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 778864 T4265 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 778866 T4265 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:39304
[junit4] 2> 778867 T4265 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 778867 T4265 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 778868 T4265 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1391251709631
[junit4] 2> 778868 T4265 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1391251709631/'
[junit4] 2> 778886 T4265 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1391251709631/solr.xml
[junit4] 2> 778919 T4296 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> 778919 T4287 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> 778934 T4265 oasc.CoreContainer.<init> New CoreContainer 1831017787
[junit4] 2> 778934 T4265 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1391251709631/]
[junit4] 2> 778935 T4265 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 778936 T4265 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 778936 T4265 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 778936 T4265 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 778936 T4265 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 778936 T4265 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 778937 T4265 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 778937 T4265 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 778937 T4265 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 778939 T4265 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 778939 T4265 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 778940 T4265 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 778940 T4265 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36436/solr
[junit4] 2> 778940 T4265 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 778941 T4265 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 778943 T4307 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c544477 name:ZooKeeperConnection Watcher:127.0.0.1:36436 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 778943 T4265 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 778945 T4265 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 778946 T4309 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5db26c0a name:ZooKeeperConnection Watcher:127.0.0.1:36436/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 778947 T4265 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 778950 T4294 oasc.ZkController.register We are http://127.0.0.1:56039/vb_j/b/collection1/ and leader is http://127.0.0.1:56039/vb_j/b/collection1/
[junit4] 2> 778951 T4294 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56039/vb_j/b
[junit4] 2> 778951 T4294 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 778951 T4294 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 778951 T4294 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 778952 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 778952 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 778952 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 778953 T4294 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 778954 T4288 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 778954 T4288 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:56039/vb_j/b",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:56039_vb_j%2Fb",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 778957 T4265 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 778957 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 779059 T4296 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> 779059 T4287 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> 779059 T4309 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> 779959 T4265 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39304_vb_j%2Fb
[junit4] 2> 779961 T4265 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39304_vb_j%2Fb
[junit4] 2> 779963 T4296 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 779963 T4309 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 779963 T4287 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 779968 T4310 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 779968 T4310 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 779969 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 779969 T4310 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 779969 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 779970 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 779971 T4288 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 779972 T4288 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:39304/vb_j/b",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:39304_vb_j%2Fb",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 779972 T4288 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 779972 T4288 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 779976 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 780078 T4287 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 780079 T4309 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 780078 T4296 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 780970 T4310 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 780970 T4310 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1391251709631/collection1
[junit4] 2> 780970 T4310 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 780971 T4310 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 780971 T4310 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 780972 T4310 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1391251709631/collection1/'
[junit4] 2> 780972 T4310 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1391251709631/collection1/lib/classes/' to classloader
[junit4] 2> 780973 T4310 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1391251709631/collection1/lib/README' to classloader
[junit4] 2> 781008 T4310 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 781055 T4310 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 781056 T4310 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 781061 T4310 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 781404 T4310 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 781406 T4310 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 781407 T4310 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 781410 T4310 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 781432 T4310 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 781432 T4310 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1391251709631/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/jetty1/
[junit4] 2> 781432 T4310 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3f42f573
[junit4] 2> 781433 T4310 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/jetty1
[junit4] 2> 781433 T4310 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/jetty1/index/
[junit4] 2> 781433 T4310 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 781434 T4310 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/jetty1/index
[junit4] 2> 781434 T4310 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=3.0537109375, floorSegmentMB=1.28125, forceMergeDeletesPctAllowed=15.707759260704117, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.20257078227297934
[junit4] 2> 781434 T4310 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@55300858 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3298768f),segFN=segments_1,generation=1}
[junit4] 2> 781435 T4310 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 781438 T4310 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 781438 T4310 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 781438 T4310 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 781438 T4310 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 781439 T4310 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 781439 T4310 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 781439 T4310 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 781439 T4310 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 781440 T4310 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 781440 T4310 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 781440 T4310 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 781441 T4310 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 781441 T4310 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 781441 T4310 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 781442 T4310 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 781442 T4310 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 781444 T4310 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 781446 T4310 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 781446 T4310 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 781447 T4310 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=15, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 781447 T4310 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@55300858 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3298768f),segFN=segments_1,generation=1}
[junit4] 2> 781447 T4310 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 781447 T4310 oass.SolrIndexSearcher.<init> Opening Searcher@6bd87f3c main
[junit4] 2> 781450 T4311 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6bd87f3c main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 781451 T4310 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 781452 T4265 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 781452 T4265 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 781452 T4314 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:39304/vb_j/b collection:collection1 shard:shard2
[junit4] 2> 781453 T4314 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 781458 T4314 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 781460 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 781460 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 781460 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 781460 T4314 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 781460 T4314 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C2085 name=collection1 org.apache.solr.core.SolrCore@5f0c5ef9 url=http://127.0.0.1:39304/vb_j/b/collection1 node=127.0.0.1:39304_vb_j%2Fb C2085_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:39304/vb_j/b, core=collection1, node_name=127.0.0.1:39304_vb_j%2Fb}
[junit4] 2> 781460 T4314 C2085 P39304 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:39304/vb_j/b/collection1/
[junit4] 2> 781461 T4314 C2085 P39304 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 781461 T4314 C2085 P39304 oasc.SyncStrategy.syncToMe http://127.0.0.1:39304/vb_j/b/collection1/ has no replicas
[junit4] 2> 781461 T4314 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:39304/vb_j/b/collection1/ shard2
[junit4] 2> 781461 T4288 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 781461 T4314 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 781463 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 781465 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 781467 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 781518 T4265 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 781518 T4265 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 781520 T4265 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:35568
[junit4] 2> 781521 T4265 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 781521 T4265 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 781521 T4265 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1391251712295
[junit4] 2> 781522 T4265 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1391251712295/'
[junit4] 2> 781536 T4265 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1391251712295/solr.xml
[junit4] 2> 781570 T4287 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 781570 T4296 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 781570 T4309 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 781580 T4265 oasc.CoreContainer.<init> New CoreContainer 1223385295
[junit4] 2> 781581 T4265 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1391251712295/]
[junit4] 2> 781581 T4265 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 781582 T4265 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 781582 T4265 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 781582 T4265 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 781582 T4265 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 781583 T4265 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 781583 T4265 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 781583 T4265 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 781583 T4265 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 781585 T4265 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 781586 T4265 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 781586 T4265 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 781586 T4265 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36436/solr
[junit4] 2> 781587 T4265 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 781587 T4265 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 781589 T4325 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5520db6f name:ZooKeeperConnection Watcher:127.0.0.1:36436 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 781589 T4265 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 781590 T4265 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 781592 T4327 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6c6605fe name:ZooKeeperConnection Watcher:127.0.0.1:36436/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 781592 T4265 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 781596 T4265 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 781616 T4314 oasc.ZkController.register We are http://127.0.0.1:39304/vb_j/b/collection1/ and leader is http://127.0.0.1:39304/vb_j/b/collection1/
[junit4] 2> 781616 T4314 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39304/vb_j/b
[junit4] 2> 781616 T4314 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 781617 T4314 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 781617 T4314 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 781618 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 781618 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 781618 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 781618 T4314 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 781619 T4288 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 781620 T4288 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:39304/vb_j/b",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:39304_vb_j%2Fb",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 781622 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 781724 T4327 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 781724 T4296 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 781724 T4309 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 781724 T4287 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 782598 T4265 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35568_vb_j%2Fb
[junit4] 2> 782600 T4265 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35568_vb_j%2Fb
[junit4] 2> 782602 T4327 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 782602 T4287 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 782602 T4309 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 782602 T4296 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 782608 T4328 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 782608 T4328 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 782610 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 782610 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 782610 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 782610 T4328 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 782611 T4288 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 782612 T4288 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:35568/vb_j/b",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:35568_vb_j%2Fb",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 782612 T4288 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 782612 T4288 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 782614 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 782717 T4287 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 782717 T4296 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 782717 T4309 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 782717 T4327 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 783610 T4328 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 783611 T4328 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1391251712295/collection1
[junit4] 2> 783611 T4328 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 783612 T4328 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 783612 T4328 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 783613 T4328 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1391251712295/collection1/'
[junit4] 2> 783613 T4328 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1391251712295/collection1/lib/classes/' to classloader
[junit4] 2> 783614 T4328 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1391251712295/collection1/lib/README' to classloader
[junit4] 2> 783659 T4328 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 783692 T4328 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 783693 T4328 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 783698 T4328 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 784032 T4328 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 784034 T4328 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 784035 T4328 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 784039 T4328 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 784061 T4328 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 784062 T4328 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1391251712295/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/jetty2/
[junit4] 2> 784062 T4328 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3f42f573
[junit4] 2> 784062 T4328 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/jetty2
[junit4] 2> 784063 T4328 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/jetty2/index/
[junit4] 2> 784063 T4328 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 784063 T4328 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/jetty2/index
[junit4] 2> 784063 T4328 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=3.0537109375, floorSegmentMB=1.28125, forceMergeDeletesPctAllowed=15.707759260704117, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.20257078227297934
[junit4] 2> 784064 T4328 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1adda161 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7eeebd65),segFN=segments_1,generation=1}
[junit4] 2> 784064 T4328 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 784067 T4328 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 784068 T4328 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 784068 T4328 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 784068 T4328 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 784068 T4328 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 784068 T4328 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 784069 T4328 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 784069 T4328 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 784069 T4328 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 784070 T4328 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 784070 T4328 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 784070 T4328 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 784071 T4328 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 784071 T4328 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 784071 T4328 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 784072 T4328 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 784074 T4328 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 784076 T4328 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 784076 T4328 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 784077 T4328 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=15, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 784077 T4328 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1adda161 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7eeebd65),segFN=segments_1,generation=1}
[junit4] 2> 784077 T4328 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 784078 T4328 oass.SolrIndexSearcher.<init> Opening Searcher@4c2e60df main
[junit4] 2> 784080 T4329 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4c2e60df main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 784082 T4328 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 784082 T4265 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 784082 T4265 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 784082 T4332 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:35568/vb_j/b collection:collection1 shard:shard1
[junit4] 2> 784084 T4332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 784088 T4332 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 784089 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 784090 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 784090 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 784090 T4332 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 784090 T4332 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C2086 name=collection1 org.apache.solr.core.SolrCore@19e83643 url=http://127.0.0.1:35568/vb_j/b/collection1 node=127.0.0.1:35568_vb_j%2Fb C2086_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:35568/vb_j/b, core=collection1, node_name=127.0.0.1:35568_vb_j%2Fb}
[junit4] 2> 784090 T4332 C2086 P35568 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:35568/vb_j/b/collection1/
[junit4] 2> 784090 T4332 C2086 P35568 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 784091 T4332 C2086 P35568 oasc.SyncStrategy.syncToMe http://127.0.0.1:35568/vb_j/b/collection1/ has no replicas
[junit4] 2> 784091 T4332 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:35568/vb_j/b/collection1/ shard1
[junit4] 2> 784091 T4332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 784091 T4288 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 784094 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 784095 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 784098 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 784145 T4265 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 784146 T4265 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 784148 T4265 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:48345
[junit4] 2> 784148 T4265 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 784148 T4265 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 784149 T4265 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1391251714925
[junit4] 2> 784149 T4265 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1391251714925/'
[junit4] 2> 784182 T4265 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1391251714925/solr.xml
[junit4] 2> 784200 T4327 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 784200 T4296 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 784200 T4287 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 784200 T4309 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 784223 T4265 oasc.CoreContainer.<init> New CoreContainer 1589988792
[junit4] 2> 784224 T4265 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1391251714925/]
[junit4] 2> 784224 T4265 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 784225 T4265 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 784225 T4265 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 784225 T4265 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 784225 T4265 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 784225 T4265 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 784226 T4265 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 784226 T4265 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 784226 T4265 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 784228 T4265 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 784228 T4265 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 784228 T4265 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 784229 T4265 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36436/solr
[junit4] 2> 784229 T4265 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 784230 T4265 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 784233 T4343 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b719ba3 name:ZooKeeperConnection Watcher:127.0.0.1:36436 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 784233 T4265 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 784236 T4265 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 784237 T4345 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5cf0bcef name:ZooKeeperConnection Watcher:127.0.0.1:36436/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 784237 T4265 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 784240 T4265 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 784245 T4332 oasc.ZkController.register We are http://127.0.0.1:35568/vb_j/b/collection1/ and leader is http://127.0.0.1:35568/vb_j/b/collection1/
[junit4] 2> 784245 T4332 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35568/vb_j/b
[junit4] 2> 784246 T4332 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 784246 T4332 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 784246 T4332 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 784247 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 784247 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 784247 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 784247 T4332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 784248 T4288 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 784249 T4288 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:35568/vb_j/b",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:35568_vb_j%2Fb",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 784251 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 784354 T4287 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 784354 T4345 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 784354 T4327 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 784354 T4309 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 784354 T4296 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 785243 T4265 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48345_vb_j%2Fb
[junit4] 2> 785244 T4265 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48345_vb_j%2Fb
[junit4] 2> 785246 T4309 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 785246 T4345 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 785246 T4287 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 785246 T4327 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 785246 T4296 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 785251 T4346 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 785251 T4346 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 785252 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 785252 T4346 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 785252 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 785253 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 785254 T4288 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 785254 T4288 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:48345/vb_j/b",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:48345_vb_j%2Fb",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 785254 T4288 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 785254 T4288 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 785256 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 785358 T4287 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 785358 T4296 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 785358 T4327 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 785358 T4345 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 785358 T4309 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 786253 T4346 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 786253 T4346 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1391251714925/collection1
[junit4] 2> 786253 T4346 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 786254 T4346 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 786254 T4346 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 786255 T4346 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1391251714925/collection1/'
[junit4] 2> 786256 T4346 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1391251714925/collection1/lib/classes/' to classloader
[junit4] 2> 786256 T4346 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1391251714925/collection1/lib/README' to classloader
[junit4] 2> 786307 T4346 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 786350 T4346 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 786351 T4346 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 786357 T4346 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 786689 T4346 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 786691 T4346 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 786692 T4346 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 786703 T4346 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 786720 T4346 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 786721 T4346 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1391251714925/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/jetty3/
[junit4] 2> 786721 T4346 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3f42f573
[junit4] 2> 786721 T4346 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/jetty3
[junit4] 2> 786721 T4346 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/jetty3/index/
[junit4] 2> 786722 T4346 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 786722 T4346 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1391251707446/jetty3/index
[junit4] 2> 786722 T4346 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=3.0537109375, floorSegmentMB=1.28125, forceMergeDeletesPctAllowed=15.707759260704117, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.20257078227297934
[junit4] 2> 786723 T4346 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9f103dd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@662c93b),segFN=segments_1,generation=1}
[junit4] 2> 786723 T4346 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 786726 T4346 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 786727 T4346 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 786727 T4346 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorC
[...truncated too long message...]
parent_f1_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 11grand10_s=FST41, 1parent_f1_s=FST41, 5child3_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 7child1_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), _version_=PostingsFormat(name=SimpleText), 9parent_f1_s=FST41, 8grand4_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 25parent_f1_s=FST41, 13grand6_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 6grand2_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 3grand2_s=FSTOrd41, 6child1_s=FST41, 4grand3_s=FSTOrd41, 1grand0_s=FST41, 12grand1_s=PostingsFormat(name=SimpleText), 18parent_f2_s=PostingsFormat(name=SimpleText), 23parent_f2_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 13grand10_s=FSTOrd41, 10grand2_s=FSTOrd41, 10grand0_s=FST41, 6child5_s=FST41, 13parent_f1_s=PostingsFormat(name=SimpleText), 21parent_f1_s=FST41, 2child0_s=PostingsFormat(name=SimpleText), 8grand2_s=PostingsFormat(name=SimpleText), 9grand7_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 7child3_s=PostingsFormat(name=SimpleText), 19parent_f1_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 13grand0_s=PostingsFormat(name=SimpleText), 8grand6_s=PostingsFormat(name=SimpleText), 12grand7_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 11grand8_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 6grand1_s=FSTOrd41, 28parent_f2_s=FST41, 3child0_s=FST41, 7child0_s=FSTOrd41, 28parent_f1_s=PostingsFormat(name=SimpleText), 10grand3_s=PostingsFormat(name=SimpleText), 7grand3_s=PostingsFormat(name=SimpleText), 7grand0_s=FST41, rnd_b=FSTOrd41, 2parent_f2_s=FST41, 11grand1_s=FST41, 12parent_f1_s=FSTOrd41, 10grand5_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 10grand8_s=FST41, 7grand5_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 13parent_f2_s=FSTOrd41, 7child4_s=FSTOrd41, 2parent_f1_s=PostingsFormat(name=SimpleText), 12grand11_s=FST41, 9grand4_s=FST41, 9grand3_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 16parent_f2_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 4parent_f2_s=FSTOrd41, id=FSTOrd41, 13grand4_s=PostingsFormat(name=SimpleText), 7child6_s=FST41, 12grand9_s=PostingsFormat(name=SimpleText), 13grand8_s=PostingsFormat(name=SimpleText), 3grand0_s=FST41, 8grand0_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 11parent_f2_s=FST41, 30parent_f2_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 7grand4_s=FST41, 3parent_f2_s=PostingsFormat(name=SimpleText), 1child0_s=FSTOrd41, 25parent_f2_s=PostingsFormat(name=SimpleText), 8grand1_s=FST41, 5child2_s=FSTOrd41, 10grand1_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 26parent_f2_s=FST41, 12grand10_s=PostingsFormat(name=SimpleText), 2grand0_s=PostingsFormat(name=SimpleText), 13grand11_s=PostingsFormat(name=SimpleText), 10grand6_s=FSTOrd41, 5child4_s=FST41, 6parent_f1_s=PostingsFormat(name=SimpleText), 11grand3_s=FSTOrd41, 6parent_f2_s=FST41, 4grand0_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), a_t=PostingsFormat(name=SimpleText), 12grand0_s=FSTOrd41, 8grand5_s=FST41, 7grand6_s=FSTOrd41, 2grand1_s=FST41, 9grand1_s=PostingsFormat(name=SimpleText), 22parent_f1_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 26parent_f1_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 3parent_f1_s=FSTOrd41, 11parent_f1_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 29parent_f1_s=FSTOrd41, 11grand0_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 6child4_s=PostingsFormat(name=SimpleText), 13grand5_s=FSTOrd41, 13grand12_s=FST41, 12grand2_s=FST41, 7grand2_s=FSTOrd41, 21parent_f2_s=PostingsFormat(name=SimpleText), 4child0_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 10grand7_s=PostingsFormat(name=SimpleText), 4grand1_s=FST41, 24parent_f2_s=FSTOrd41, 4child1_s=FSTOrd41, 13grand3_s=FST41, 7child2_s=FST41, 5parent_f1_s=FST41, 11grand9_s=FST41, 9grand5_s=PostingsFormat(name=SimpleText), 3child1_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 0parent_f2_s=FSTOrd41, 5grand0_s=FSTOrd41, 3grand1_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 10grand4_s=FST41, 12grand6_s=FST41, 12parent_f2_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 9parent_f2_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), _root_=PostingsFormat(name=SimpleText), 9grand8_s=FST41, 6grand4_s=PostingsFormat(name=SimpleText), 4parent_f1_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 14parent_f1_s=FST41, 4child2_s=PostingsFormat(name=SimpleText), 13grand7_s=FST41, 23parent_f1_s=FSTOrd41, 11grand7_s=FSTOrd41, 5grand4_s=FSTOrd41, 3child2_s=FSTOrd41, 13grand9_s=FSTOrd41, 9grand0_s=FST41, 8parent_f1_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 15parent_f2_s=FST41, 6grand3_s=FST41, 13grand2_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 9grand6_s=FSTOrd41, 8parent_f2_s=FSTOrd41, 22parent_f2_s=FST41, 5grand3_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 8grand3_s=FSTOrd41, 24parent_f1_s=PostingsFormat(name=SimpleText), 4grand2_s=PostingsFormat(name=SimpleText), 6grand5_s=FSTOrd41, 6child3_s=FSTOrd41, 17parent_f2_s=FST41, 29parent_f2_s=PostingsFormat(name=SimpleText), 16parent_f1_s=FST41, 20parent_f1_s=PostingsFormat(name=SimpleText), 12grand4_s=FSTOrd41, 5grand1_s=PostingsFormat(name=SimpleText), 14parent_f2_s=PostingsFormat(name=SimpleText), type_s=PostingsFormat(name=SimpleText), 12grand3_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 12grand5_s=PostingsFormat(name=SimpleText), 10parent_f1_s=FST41, 5grand2_s=FST41, 4child3_s=FST41, 11grand4_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 5child1_s=PostingsFormat(name=SimpleText), 11grand2_s=PostingsFormat(name=SimpleText), 6child0_s=PostingsFormat(name=SimpleText), 8grand7_s=FSTOrd41, 9grand2_s=FSTOrd41, 7child5_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 6grand0_s=PostingsFormat(name=SimpleText), 12grand8_s=FSTOrd41, 18parent_f1_s=FSTOrd41, 27parent_f2_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), 5child0_s=FST41, 7parent_f1_s=FSTOrd41, 1parent_f2_s=PostingsFormat(name=TestBloomFilteredLucene41Postings)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=ar_EG, timezone=America/Nipigon
[junit4] 2> NOTE: Linux 3.8.0-35-generic amd64/Oracle Corporation 1.7.0_51 (64-bit)/cpus=8,threads=6,free=79109960,total=258170880
[junit4] 2> NOTE: All tests run in this JVM: [TestReloadAndDeleteDocs, TestSchemaNameResource, TestCopyFieldCollectionResource, TestManagedSchema, TestFaceting, TestQueryUtils, TestJmxMonitoredMap, DeleteShardTest, SolrXmlInZkTest, TestExtendedDismaxParser, TermsComponentTest, TestSolrXmlPersistor, TestLMJelinekMercerSimilarityFactory, TestLuceneMatchVersion, SyncSliceTest, SpatialFilterTest, SolrIndexSplitterTest, BasicFunctionalityTest, OverseerCollectionProcessorTest, TestSolrQueryParser, CoreAdminHandlerTest, QueryParsingTest, RecoveryZkTest, TestValueSourceCache, CircularListTest, ResponseLogComponentTest, BlockCacheTest, TestAddFieldRealTimeGet, TriLevelCompositeIdRoutingTest, TestSolrIndexConfig, SolrCoreTest, TestFieldTypeCollectionResource, CSVRequestHandlerTest, SimpleFacetsTest, SliceStateUpdateTest, EnumFieldTest, TestUniqueKeyFieldResource, PrimitiveFieldTypeTest, PreAnalyzedUpdateProcessorTest, MoreLikeThisHandlerTest, TestCharFilters, ShardRoutingTest, SolrInfoMBeanTest, BadComponentTest, SchemaVersionSpecificBehaviorTest, SoftAutoCommitTest, SpellPossibilityIteratorTest, StatelessScriptUpdateProcessorFactoryTest, TestAnalyzeInfixSuggestions, TestMaxScoreQueryParser, BJQParserTest, DocValuesTest, TestPerFieldSimilarity, TestCloudManagedSchema, TestReplicationHandler, ReturnFieldsTest, TestSolrDeletionPolicy1, TestPostingsSolrHighlighter, SearchHandlerTest, TestOverriddenPrefixQueryForCustomFieldType, UnloadDistributedZkTest, BinaryUpdateRequestHandlerTest, TestLRUCache, OverseerRolesTest, TestSearchPerf, QueryEqualityTest, LukeRequestHandlerTest, TestCollapseQParserPlugin, ClusterStateUpdateTest, TestBM25SimilarityFactory, RegexBoostProcessorTest, CopyFieldTest, OverseerTest, WordBreakSolrSpellCheckerTest, TestDistributedMissingSort, QueryResultKeyTest, ScriptEngineTest, TestGroupingSearch, TestSystemIdResolver, HdfsLockFactoryTest, UpdateParamsTest, MBeansHandlerTest, TestLMDirichletSimilarityFactory, TestCollationFieldDocValues, TestHighFrequencyDictionaryFactory, BasicDistributedZkTest, OpenCloseCoreStressTest, LeaderElectionIntegrationTest, FullSolrCloudDistribCmdsTest]
[junit4] Completed on J0 in 129.76s, 1 test, 1 error <<< FAILURES!
[...truncated 609 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:459: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:439: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1308: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:941: There were test failures: 355 suites, 1549 tests, 1 error, 35 ignored (7 assumptions)
Total time: 51 minutes 31 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_51 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure