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 2013/06/27 10:50:39 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/ibm-j9-jdk7) - Build # 6260
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/6260/
Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
1 tests failed.
FAILED: org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch
Error Message:
Server at http://127.0.0.1:53079/qdr/s/onenodecollectioncore returned non ok status:404, message:Can not find: /qdr/s/onenodecollectioncore/update
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:53079/qdr/s/onenodecollectioncore returned non ok status:404, message:Can not find: /qdr/s/onenodecollectioncore/update
at __randomizedtesting.SeedInfo.seed([8710E3543D9C6EA8:6F66D4C4AC30E94]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:198)
at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:90)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
at java.lang.reflect.Method.invoke(Method.java:613)
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:780)
Build Log:
[...truncated 9790 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4] 2> 602603 T2044 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /qdr/s
[junit4:junit4] 2> 602607 T2044 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372322519035
[junit4:junit4] 2> 602608 T2044 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 602609 T2045 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 602709 T2044 oasc.ZkTestServer.run start zk server on port:52176
[junit4:junit4] 2> 602711 T2044 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 602733 T2051 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9755c758 name:ZooKeeperConnection Watcher:127.0.0.1:52176 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 602734 T2044 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 602735 T2044 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 602741 T2044 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 602743 T2053 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c636c2e name:ZooKeeperConnection Watcher:127.0.0.1:52176/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 602743 T2044 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 602745 T2044 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 602749 T2044 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 602754 T2044 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 602758 T2044 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 602764 T2044 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:junit4] 2> 602765 T2044 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 602772 T2044 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 602774 T2044 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 602779 T2044 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:junit4] 2> 602780 T2044 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 602785 T2044 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:junit4] 2> 602786 T2044 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 602791 T2044 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:junit4] 2> 602792 T2044 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 602796 T2044 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:junit4] 2> 602798 T2044 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 602802 T2044 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:junit4] 2> 602804 T2044 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 602808 T2044 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:junit4] 2> 602809 T2044 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 602813 T2044 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:junit4] 2> 602814 T2044 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 602890 T2044 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 602894 T2044 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:37238
[junit4:junit4] 2> 602895 T2044 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 602896 T2044 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 602897 T2044 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1372322519243
[junit4:junit4] 2> 602898 T2044 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1372322519243/solr.xml
[junit4:junit4] 2> 602899 T2044 oasc.CoreContainer.<init> New CoreContainer -1258355980
[junit4:junit4] 2> 602900 T2044 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1372322519243/'
[junit4:junit4] 2> 602901 T2044 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1372322519243/'
[junit4:junit4] 2> 602950 T2044 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 602950 T2044 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 602951 T2044 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 602952 T2044 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 602952 T2044 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 602953 T2044 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 602953 T2044 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 602954 T2044 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 602955 T2044 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 602955 T2044 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 602960 T2044 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 602961 T2044 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52176/solr
[junit4:junit4] 2> 602961 T2044 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 602963 T2044 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 602964 T2064 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19712be7 name:ZooKeeperConnection Watcher:127.0.0.1:52176 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 602964 T2044 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 602966 T2044 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 602974 T2044 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 602975 T2066 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bc709125 name:ZooKeeperConnection Watcher:127.0.0.1:52176/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 602975 T2044 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 602981 T2044 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 602984 T2044 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 602986 T2044 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 602988 T2044 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37238_qdr%2Fs
[junit4:junit4] 2> 602989 T2044 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37238_qdr%2Fs
[junit4:junit4] 2> 602991 T2044 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 602996 T2044 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 602997 T2044 oasc.Overseer.start Overseer (id=89936528607739907-127.0.0.1:37238_qdr%2Fs-n_0000000000) starting
[junit4:junit4] 2> 603000 T2044 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 603003 T2068 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 603003 T2044 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 603005 T2044 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 603007 T2044 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 603009 T2067 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 603011 T2069 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 603011 T2069 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 604511 T2067 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 604512 T2067 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:37238/qdr/s",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:37238_qdr%2Fs",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 604512 T2067 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 604513 T2067 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 604516 T2066 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 605013 T2069 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1372322519243/collection1
[junit4:junit4] 2> 605013 T2069 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 605014 T2069 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 605014 T2069 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 605015 T2069 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1372322519243/collection1/'
[junit4:junit4] 2> 605016 T2069 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1372322519243/collection1/lib/README' to classloader
[junit4:junit4] 2> 605016 T2069 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1372322519243/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 605039 T2069 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 605068 T2069 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 605070 T2069 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 605074 T2069 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 605384 T2069 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 605385 T2069 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 605385 T2069 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 605391 T2069 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 605394 T2069 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 605407 T2069 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 605411 T2069 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 605414 T2069 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 605416 T2069 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 605416 T2069 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 605417 T2069 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 605419 T2069 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 605419 T2069 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 605420 T2069 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 605421 T2069 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1372322519243/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/control/data/
[junit4:junit4] 2> 605421 T2069 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c2a0362
[junit4:junit4] 2> 605422 T2069 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 605423 T2069 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/control/data
[junit4:junit4] 2> 605424 T2069 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/control/data/index/
[junit4:junit4] 2> 605424 T2069 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 605425 T2069 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/control/data/index
[junit4:junit4] 2> 605427 T2069 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@41b3ad15 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5e0c3130),segFN=segments_1,generation=1}
[junit4:junit4] 2> 605428 T2069 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 605430 T2069 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 605431 T2069 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 605432 T2069 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 605433 T2069 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 605434 T2069 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 605434 T2069 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 605435 T2069 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 605436 T2069 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 605436 T2069 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 605438 T2069 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 605441 T2069 oass.SolrIndexSearcher.<init> Opening Searcher@9bb25184 main
[junit4:junit4] 2> 605442 T2069 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/control/data/tlog
[junit4:junit4] 2> 605443 T2069 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 605444 T2069 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 605449 T2070 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9bb25184 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 605450 T2069 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 605451 T2069 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:37238/qdr/s collection:control_collection shard:shard1
[junit4:junit4] 2> 605452 T2069 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 605461 T2069 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 605465 T2069 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 605465 T2069 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 605466 T2069 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:37238/qdr/s/collection1/
[junit4:junit4] 2> 605467 T2069 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 605468 T2069 oasc.SyncStrategy.syncToMe http://127.0.0.1:37238/qdr/s/collection1/ has no replicas
[junit4:junit4] 2> 605469 T2069 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:37238/qdr/s/collection1/
[junit4:junit4] 2> 605469 T2069 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 606019 T2067 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 606028 T2066 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 606079 T2069 oasc.ZkController.register We are http://127.0.0.1:37238/qdr/s/collection1/ and leader is http://127.0.0.1:37238/qdr/s/collection1/
[junit4:junit4] 2> 606080 T2069 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:37238/qdr/s
[junit4:junit4] 2> 606081 T2069 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 606081 T2069 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 606082 T2069 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 606084 T2069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 606086 T2044 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 606088 T2044 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 606090 T2044 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 606103 T2044 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 606107 T2044 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 606109 T2073 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@baf2fffe name:ZooKeeperConnection Watcher:127.0.0.1:52176/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 606110 T2044 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 606112 T2044 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 606116 T2044 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 606205 T2044 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 606207 T2044 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:42216
[junit4:junit4] 2> 606208 T2044 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 606208 T2044 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 606209 T2044 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372322522544
[junit4:junit4] 2> 606209 T2044 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372322522544/solr.xml
[junit4:junit4] 2> 606210 T2044 oasc.CoreContainer.<init> New CoreContainer 2048569871
[junit4:junit4] 2> 606211 T2044 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372322522544/'
[junit4:junit4] 2> 606211 T2044 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372322522544/'
[junit4:junit4] 2> 606249 T2044 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 606249 T2044 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 606250 T2044 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 606251 T2044 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 606251 T2044 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 606252 T2044 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 606252 T2044 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 606253 T2044 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 606254 T2044 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 606254 T2044 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 606259 T2044 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 606260 T2044 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52176/solr
[junit4:junit4] 2> 606260 T2044 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 606262 T2044 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 606263 T2084 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@96986dc6 name:ZooKeeperConnection Watcher:127.0.0.1:52176 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 606263 T2044 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 606265 T2044 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 606269 T2044 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 606270 T2086 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9fb8a377 name:ZooKeeperConnection Watcher:127.0.0.1:52176/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 606271 T2044 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 606273 T2044 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 607276 T2044 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42216_qdr%2Fs
[junit4:junit4] 2> 607277 T2044 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42216_qdr%2Fs
[junit4:junit4] 2> 607280 T2073 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 607280 T2066 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 607280 T2086 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 607281 T2066 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 607284 T2087 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 607285 T2087 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 607535 T2067 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 607536 T2067 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:37238/qdr/s",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:37238_qdr%2Fs_collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:37238_qdr%2Fs",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 607539 T2067 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42216/qdr/s",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42216_qdr%2Fs",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 607539 T2067 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 607540 T2067 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 607543 T2066 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 607543 T2073 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 607543 T2086 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 608286 T2087 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372322522544/collection1
[junit4:junit4] 2> 608286 T2087 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 608287 T2087 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 608288 T2087 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 608289 T2087 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372322522544/collection1/'
[junit4:junit4] 2> 608289 T2087 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372322522544/collection1/lib/README' to classloader
[junit4:junit4] 2> 608290 T2087 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372322522544/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 608313 T2087 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 608349 T2087 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 608350 T2087 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 608355 T2087 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 608666 T2087 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 608666 T2087 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 608667 T2087 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 608673 T2087 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 608676 T2087 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 608688 T2087 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 608692 T2087 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 608696 T2087 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 608697 T2087 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 608697 T2087 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 608698 T2087 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 608699 T2087 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 608699 T2087 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 608700 T2087 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 608700 T2087 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372322522544/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty1/
[junit4:junit4] 2> 608700 T2087 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c2a0362
[junit4:junit4] 2> 608701 T2087 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 608702 T2087 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty1
[junit4:junit4] 2> 608702 T2087 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty1/index/
[junit4:junit4] 2> 608702 T2087 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 608703 T2087 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty1/index
[junit4:junit4] 2> 608704 T2087 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@88ebb192 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6646cb0e),segFN=segments_1,generation=1}
[junit4:junit4] 2> 608705 T2087 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 608707 T2087 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 608707 T2087 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 608708 T2087 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 608708 T2087 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 608709 T2087 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 608709 T2087 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 608710 T2087 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 608710 T2087 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 608711 T2087 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 608712 T2087 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 608714 T2087 oass.SolrIndexSearcher.<init> Opening Searcher@2d73704c main
[junit4:junit4] 2> 608714 T2087 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty1/tlog
[junit4:junit4] 2> 608715 T2087 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 608715 T2087 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 608720 T2088 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2d73704c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 608722 T2087 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 608722 T2087 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42216/qdr/s collection:collection1 shard:shard1
[junit4:junit4] 2> 608723 T2087 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 608729 T2087 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 608732 T2087 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 608732 T2087 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 608733 T2087 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:42216/qdr/s/collection1/
[junit4:junit4] 2> 608733 T2087 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 608734 T2087 oasc.SyncStrategy.syncToMe http://127.0.0.1:42216/qdr/s/collection1/ has no replicas
[junit4:junit4] 2> 608734 T2087 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:42216/qdr/s/collection1/
[junit4:junit4] 2> 608735 T2087 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 609048 T2067 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 609053 T2066 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 609053 T2086 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 609054 T2073 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 609091 T2087 oasc.ZkController.register We are http://127.0.0.1:42216/qdr/s/collection1/ and leader is http://127.0.0.1:42216/qdr/s/collection1/
[junit4:junit4] 2> 609091 T2087 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42216/qdr/s
[junit4:junit4] 2> 609092 T2087 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 609092 T2087 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 609092 T2087 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 609094 T2087 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 609096 T2044 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 609096 T2044 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 609097 T2044 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 609180 T2044 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 609182 T2044 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53079
[junit4:junit4] 2> 609183 T2044 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 609184 T2044 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 609184 T2044 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1372322525530
[junit4:junit4] 2> 609185 T2044 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1372322525530/solr.xml
[junit4:junit4] 2> 609186 T2044 oasc.CoreContainer.<init> New CoreContainer -117233923
[junit4:junit4] 2> 609187 T2044 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1372322525530/'
[junit4:junit4] 2> 609188 T2044 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1372322525530/'
[junit4:junit4] 2> 609234 T2044 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 609235 T2044 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 609236 T2044 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 609236 T2044 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 609237 T2044 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 609238 T2044 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 609238 T2044 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 609239 T2044 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 609240 T2044 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 609240 T2044 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 609247 T2044 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 609249 T2044 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52176/solr
[junit4:junit4] 2> 609250 T2044 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 609251 T2044 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 609254 T2100 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@43edc1da name:ZooKeeperConnection Watcher:127.0.0.1:52176 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 609254 T2044 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 609257 T2044 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 609262 T2044 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 609264 T2102 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7997ea43 name:ZooKeeperConnection Watcher:127.0.0.1:52176/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 609265 T2044 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 609272 T2044 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 610275 T2044 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53079_qdr%2Fs
[junit4:junit4] 2> 610277 T2044 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53079_qdr%2Fs
[junit4:junit4] 2> 610279 T2086 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 610279 T2073 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 610279 T2066 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 610279 T2102 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 610280 T2073 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 610280 T2066 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 610279 T2086 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 610284 T2103 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 610284 T2103 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 610559 T2067 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 610560 T2067 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42216/qdr/s",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:42216_qdr%2Fs_collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:42216_qdr%2Fs",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 610565 T2067 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53079/qdr/s",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53079_qdr%2Fs",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 610565 T2067 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 610566 T2067 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 610568 T2086 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 610568 T2073 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 610568 T2102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 610568 T2066 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 611285 T2103 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1372322525530/collection1
[junit4:junit4] 2> 611286 T2103 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 611288 T2103 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 611289 T2103 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 611291 T2103 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1372322525530/collection1/'
[junit4:junit4] 2> 611292 T2103 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1372322525530/collection1/lib/README' to classloader
[junit4:junit4] 2> 611293 T2103 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1372322525530/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 611326 T2103 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 611355 T2103 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 611356 T2103 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 611360 T2103 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 611682 T2103 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 611683 T2103 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 611684 T2103 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 611689 T2103 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 611692 T2103 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 611706 T2103 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 611713 T2103 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 611720 T2103 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 611722 T2103 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 611723 T2103 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 611724 T2103 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 611726 T2103 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 611727 T2103 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 611727 T2103 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 611728 T2103 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1372322525530/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty2/
[junit4:junit4] 2> 611729 T2103 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c2a0362
[junit4:junit4] 2> 611731 T2103 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 611732 T2103 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty2
[junit4:junit4] 2> 611733 T2103 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty2/index/
[junit4:junit4] 2> 611734 T2103 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 611735 T2103 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty2/index
[junit4:junit4] 2> 611738 T2103 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8774a738 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4691345a),segFN=segments_1,generation=1}
[junit4:junit4] 2> 611739 T2103 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 611742 T2103 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 611743 T2103 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 611744 T2103 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 611746 T2103 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 611747 T2103 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 611748 T2103 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 611749 T2103 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 611750 T2103 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 611751 T2103 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 611754 T2103 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 611756 T2103 oass.SolrIndexSearcher.<init> Opening Searcher@a7328d06 main
[junit4:junit4] 2> 611757 T2103 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty2/tlog
[junit4:junit4] 2> 611758 T2103 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 611758 T2103 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 611762 T2104 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@a7328d06 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 611765 T2103 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 611766 T2103 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53079/qdr/s collection:collection1 shard:shard2
[junit4:junit4] 2> 611767 T2103 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 611773 T2103 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 611776 T2103 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 611777 T2103 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 611778 T2103 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53079/qdr/s/collection1/
[junit4:junit4] 2> 611779 T2103 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 611779 T2103 oasc.SyncStrategy.syncToMe http://127.0.0.1:53079/qdr/s/collection1/ has no replicas
[junit4:junit4] 2> 611780 T2103 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53079/qdr/s/collection1/
[junit4:junit4] 2> 611781 T2103 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 612077 T2067 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 612086 T2066 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 612086 T2086 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 612087 T2073 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 612086 T2102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 612138 T2103 oasc.ZkController.register We are http://127.0.0.1:53079/qdr/s/collection1/ and leader is http://127.0.0.1:53079/qdr/s/collection1/
[junit4:junit4] 2> 612139 T2103 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53079/qdr/s
[junit4:junit4] 2> 612140 T2103 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 612141 T2103 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 612141 T2103 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 612144 T2103 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 612146 T2044 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 612147 T2044 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 612149 T2044 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 612235 T2044 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 612238 T2044 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49474
[junit4:junit4] 2> 612238 T2044 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 612239 T2044 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 612240 T2044 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1372322528585
[junit4:junit4] 2> 612240 T2044 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1372322528585/solr.xml
[junit4:junit4] 2> 612241 T2044 oasc.CoreContainer.<init> New CoreContainer 2106310151
[junit4:junit4] 2> 612242 T2044 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1372322528585/'
[junit4:junit4] 2> 612242 T2044 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1372322528585/'
[junit4:junit4] 2> 612283 T2044 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 612284 T2044 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 612284 T2044 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 612285 T2044 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 612286 T2044 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 612286 T2044 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 612287 T2044 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 612288 T2044 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 612288 T2044 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 612289 T2044 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 612293 T2044 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 612294 T2044 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52176/solr
[junit4:junit4] 2> 612295 T2044 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 612296 T2044 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 612297 T2116 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8d7e36f6 name:ZooKeeperConnection Watcher:127.0.0.1:52176 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 612297 T2044 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 612299 T2044 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 612304 T2044 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 612305 T2118 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@193d23e8 name:ZooKeeperConnection Watcher:127.0.0.1:52176/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 612305 T2044 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 612309 T2044 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 613312 T2044 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49474_qdr%2Fs
[junit4:junit4] 2> 613313 T2044 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49474_qdr%2Fs
[junit4:junit4] 2> 613315 T2102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 613315 T2073 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 613316 T2066 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 613316 T2066 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 613316 T2086 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 613316 T2073 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 613316 T2118 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 613317 T2086 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 613317 T2102 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 613320 T2119 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 613321 T2119 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 613594 T2067 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 613596 T2067 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53079/qdr/s",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:53079_qdr%2Fs_collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:53079_qdr%2Fs",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 613601 T2067 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49474/qdr/s",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49474_qdr%2Fs",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 613602 T2067 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 613602 T2067 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 613608 T2102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 613608 T2073 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 613608 T2086 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 613609 T2066 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 613608 T2118 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 614322 T2119 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1372322528585/collection1
[junit4:junit4] 2> 614322 T2119 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 614324 T2119 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 614324 T2119 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 614326 T2119 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1372322528585/collection1/'
[junit4:junit4] 2> 614328 T2119 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1372322528585/collection1/lib/README' to classloader
[junit4:junit4] 2> 614329 T2119 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1372322528585/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 614365 T2119 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 614404 T2119 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 614405 T2119 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 614410 T2119 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 614774 T2119 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 614774 T2119 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 614776 T2119 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 614782 T2119 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 614785 T2119 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 614798 T2119 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 614804 T2119 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 614810 T2119 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 614811 T2119 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 614812 T2119 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 614812 T2119 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 614814 T2119 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 614814 T2119 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 614815 T2119 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 614815 T2119 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1372322528585/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty3/
[junit4:junit4] 2> 614816 T2119 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c2a0362
[junit4:junit4] 2> 614816 T2119 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 614817 T2119 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty3
[junit4:junit4] 2> 614817 T2119 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty3/index/
[junit4:junit4] 2> 614818 T2119 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 614818 T2119 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty3/index
[junit4:junit4] 2> 614820 T2119 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@d8be4c19 lockFactory=org.apache.lucene.store.NativeFSLockFactory@ab4e5ae9),segFN=segments_1,generation=1}
[junit4:junit4] 2> 614820 T2119 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 614822 T2119 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 614822 T2119 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 614823 T2119 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 614824 T2119 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 614824 T2119 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 614825 T2119 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 614825 T2119 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 614826 T2119 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 614826 T2119 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 614828 T2119 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 614830 T2119 oass.SolrIndexSearcher.<init> Opening Searcher@cf894256 main
[junit4:junit4] 2> 614830 T2119 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty3/tlog
[junit4:junit4] 2> 614831 T2119 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 614831 T2119 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 614835 T2120 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@cf894256 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 614836 T2119 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 614837 T2119 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49474/qdr/s collection:collection1 shard:shard1
[junit4:junit4] 2> 614839 T2119 oasc.ZkController.register We are http://127.0.0.1:49474/qdr/s/collection1/ and leader is http://127.0.0.1:42216/qdr/s/collection1/
[junit4:junit4] 2> 614839 T2119 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49474/qdr/s
[junit4:junit4] 2> 614839 T2119 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 614840 T2119 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C785 name=collection1 org.apache.solr.core.SolrCore@1b645147 url=http://127.0.0.1:49474/qdr/s/collection1 node=127.0.0.1:49474_qdr%2Fs C785_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:49474/qdr/s, state=down, node_name=127.0.0.1:49474_qdr%2Fs, collection=collection1, core=collection1}
[junit4:junit4] 2> 614840 T2121 C785 P49474 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 614840 T2119 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 614841 T2121 C785 P49474 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 614841 T2121 C785 P49474 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 614842 T2121 C785 P49474 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 614842 T2044 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 614843 T2044 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 614842 T2121 C785 P49474 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 614844 T2044 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 614849 T2082 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:49474_qdr%2Fs_collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 614945 T2044 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 614947 T2044 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:37320
[junit4:junit4] 2> 614948 T2044 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 614949 T2044 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 614949 T2044 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1372322531279
[junit4:junit4] 2> 614950 T2044 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1372322531279/solr.xml
[junit4:junit4] 2> 614950 T2044 oasc.CoreContainer.<init> New CoreContainer -762702526
[junit4:junit4] 2> 614951 T2044 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1372322531279/'
[junit4:junit4] 2> 614952 T2044 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1372322531279/'
[junit4:junit4] 2> 614989 T2044 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 614989 T2044 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 614990 T2044 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 614991 T2044 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 614991 T2044 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 614992 T2044 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 614992 T2044 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 614993 T2044 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 614993 T2044 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 614994 T2044 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 614999 T2044 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 614999 T2044 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52176/solr
[junit4:junit4] 2> 615000 T2044 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 615001 T2044 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 615002 T2133 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6340414b name:ZooKeeperConnection Watcher:127.0.0.1:52176 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 615003 T2044 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 615005 T2044 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 615009 T2044 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 615010 T2135 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4d147326 name:ZooKeeperConnection Watcher:127.0.0.1:52176/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 615011 T2044 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 615014 T2044 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 615115 T2067 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 615116 T2067 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49474/qdr/s",
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:49474_qdr%2Fs_collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:49474_qdr%2Fs",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 615119 T2066 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 615119 T2118 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 615119 T2086 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 615119 T2073 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 615119 T2135 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 615119 T2102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 615850 T2082 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:49474_qdr%2Fs_collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 615851 T2082 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={state=recovering&onlyIfLeader=true&checkLive=true&action=PREPRECOVERY&version=2&coreNodeName=127.0.0.1:49474_qdr%252Fs_collection1&wt=javabin&nodeName=127.0.0.1:49474_qdr%252Fs&core=collection1} status=0 QTime=1002
[junit4:junit4] 2> 616017 T2044 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37320_qdr%2Fs
[junit4:junit4] 2> 616020 T2044 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37320_qdr%2Fs
[junit4:junit4] 2> 616023 T2102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 616023 T2135 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 616024 T2066 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 616023 T2118 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 616024 T2073 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 616026 T2102 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 616024 T2086 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 616025 T2066 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 616026 T2135 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 616027 T2118 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 616027 T2086 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 616026 T2073 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 616033 T2136 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 616034 T2136 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 616625 T2067 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 616626 T2067 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:37320/qdr/s",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:37320_qdr%2Fs",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 616627 T2067 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 616628 T2067 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 616632 T2066 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 616632 T2102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 616632 T2073 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 616632 T2118 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 616632 T2086 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 616632 T2135 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 617037 T2136 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1372322531279/collection1
[junit4:junit4] 2> 617037 T2136 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 617038 T2136 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 617038 T2136 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 617040 T2136 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1372322531279/collection1/'
[junit4:junit4] 2> 617040 T2136 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1372322531279/collection1/lib/README' to classloader
[junit4:junit4] 2> 617041 T2136 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1372322531279/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 617074 T2136 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 617113 T2136 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 617115 T2136 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 617120 T2136 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 617604 T2136 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 617605 T2136 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 617606 T2136 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 617624 T2136 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 617629 T2136 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 617658 T2136 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 617664 T2136 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 617673 T2136 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 617674 T2136 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 617675 T2136 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 617675 T2136 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 617676 T2136 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 617676 T2136 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 617677 T2136 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 617678 T2136 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1372322531279/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty4/
[junit4:junit4] 2> 617678 T2136 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c2a0362
[junit4:junit4] 2> 617679 T2136 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 617679 T2136 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty4
[junit4:junit4] 2> 617680 T2136 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty4/index/
[junit4:junit4] 2> 617680 T2136 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 617680 T2136 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty4/index
[junit4:junit4] 2> 617682 T2136 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@ff963c8e lockFactory=org.apache.lucene.store.NativeFSLockFactory@9dd40c99),segFN=segments_1,generation=1}
[junit4:junit4] 2> 617683 T2136 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 617685 T2136 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 617685 T2136 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 617686 T2136 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 617687 T2136 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 617688 T2136 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 617689 T2136 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 617689 T2136 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 617690 T2136 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 617691 T2136 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 617694 T2136 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 617700 T2136 oass.SolrIndexSearcher.<init> Opening Searcher@964a0391 main
[junit4:junit4] 2> 617702 T2136 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty4/tlog
[junit4:junit4] 2> 617705 T2136 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 617707 T2136 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 617723 T2137 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@964a0391 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 617725 T2136 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 617726 T2136 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:37320/qdr/s collection:collection1 shard:shard2
[junit4:junit4] 2> 617736 T2136 oasc.ZkController.register We are http://127.0.0.1:37320/qdr/s/collection1/ and leader is http://127.0.0.1:53079/qdr/s/collection1/
[junit4:junit4] 2> 617738 T2136 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:37320/qdr/s
[junit4:junit4] 2> 617739 T2136 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 617740 T2136 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 617743 T2136 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C786 name=collection1 org.apache.solr.core.SolrCore@72952512 url=http://127.0.0.1:37320/qdr/s/collection1 node=127.0.0.1:37320_qdr%2Fs C786_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:37320/qdr/s, state=down, node_name=127.0.0.1:37320_qdr%2Fs, collection=collection1, core=collection1}
[junit4:junit4] 2> 617744 T2138 C786 P37320 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 617745 T2044 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4] 2> 617747 T2044 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 617748 T2044 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 617753 T2138 C786 P37320 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 617754 T2138 C786 P37320 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 617756 T2138 C786 P37320 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 617759 T2138 C786 P37320 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 617759 T2044 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 617766 T2044 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 617778 T2097 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:37320_qdr%2Fs_collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 617783 T2079 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> ASYNC NEW_CORE C787 name=collection1 org.apache.solr.core.SolrCore@1b645147 url=http://127.0.0.1:49474/qdr/s/collection1 node=127.0.0.1:49474_qdr%2Fs C787_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:49474/qdr/s, state=recovering, node_name=127.0.0.1:49474_qdr%2Fs, collection=collection1, shard=shard1, core=collection1}
[junit4:junit4] 2> 617854 T2121 C787 P49474 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:42216/qdr/s/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 617854 T2121 C787 P49474 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:49474/qdr/s START replicas=[http://127.0.0.1:42216/qdr/s/collection1/] nUpdates=100
[junit4:junit4] 2> 617855 T2121 C787 P49474 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 617855 T2121 C787 P49474 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 617855 T2121 C787 P49474 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 617857 T2121 C787 P49474 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 617857 T2121 C787 P49474 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 617858 T2121 C787 P49474 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:42216/qdr/s/collection1/. core=collection1
[junit4:junit4] 2> 617858 T2121 C787 P49474 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C788 name=collection1 org.apache.solr.core.SolrCore@2b936c08 url=http://127.0.0.1:42216/qdr/s/collection1 node=127.0.0.1:42216_qdr%2Fs C788_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:42216/qdr/s, state=active, node_name=127.0.0.1:42216_qdr%2Fs, collection=collection1, shard=shard1, core=collection1, leader=true}
[junit4:junit4] 2> 617863 T2081 C788 P42216 oasc.SolrCore.execute [collection1] webapp=/qdr/s path=/get params={getVersions=100&qt=/get&distrib=false&version=2&wt=javabin} status=0 QTime=0
[junit4:junit4] 2> 617866 T2080 C788 P42216 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 617867 T2080 C788 P42216 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@88ebb192 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6646cb0e),segFN=segments_1,generation=1}
[junit4:junit4] 2> 617868 T2080 C788 P42216 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 617869 T2080 C788 P42216 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4] 2> 617871 T2080 C788 P42216 oass.SolrIndexSearcher.<init> Opening Searcher@aa80b244 realtime
[junit4:junit4] 2> 617872 T2080 C788 P42216 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 617873 T2080 C788 P42216 oasup.LogUpdateProcessor.finish [collection1] webapp=/qdr/s path=/update params={softCommit=false&commit_end_point=true&commit=true&version=2&waitSearcher=true&wt=javabin&openSearcher=false} {commit=} 0 7
[junit4:junit4] 2> 617874 T2121 C787 P49474 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 617874 T2121 C787 P49474 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 617876 T2081 C788 P42216 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 617877 T2081 C788 P42216 oasc.SolrCore.execute [collection1] webapp=/qdr/s path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=2
[junit4:junit4] 2> 617878 T2121 C787 P49474 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 617879 T2121 C787 P49474 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 617879 T2121 C787 P49474 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 617879 T2121 C787 P49474 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 617888 T2121 C787 P49474 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 618137 T2067 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 618139 T2067 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:37320/qdr/s",
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:37320_qdr%2Fs_collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:37320_qdr%2Fs",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 618143 T2067 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42216/qdr/s",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42216_qdr%2Fs",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "core":"onenodecollectioncore"}
[junit4:junit4] 2> 618144 T2067 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4] 2> 618144 T2067 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 618148 T2067 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49474/qdr/s",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:49474_qdr%2Fs_collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:49474_qdr%2Fs",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 618156 T2073 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 618156 T2086 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 618156 T2135 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 618156 T2118 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 618156 T2102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 618159 T2066 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 618779 T2097 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:37320_qdr%2Fs_collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 618781 T2097 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={state=recovering&onlyIfLeader=true&checkLive=true&action=PREPRECOVERY&version=2&coreNodeName=127.0.0.1:37320_qdr%252Fs_collection1&wt=javabin&nodeName=127.0.0.1:37320_qdr%252Fs&core=collection1} status=0 QTime=1003
[junit4:junit4] 2> 618785 T2079 oasc.CoreContainer.create Creating SolrCore 'onenodecollectioncore' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372322522544/onenodecollectioncore
[junit4:junit4] 2> 618787 T2079 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4] 2> 618788 T2079 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4] 2> 618789 T2079 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 618790 T2079 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 618791 T2079 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4] 2> 618794 T2079 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4] 2> 618795 T2079 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372322522544/onenodecollectioncore/'
[junit4:junit4] 2> 618833 T2079 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 618881 T2079 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 618883 T2079 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 618890 T2079 oass.IndexSchema.readSchema [onenodecollectioncore] Schema name=test
[junit4:junit4] 2> 619250 T2079 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 619250 T2079 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 619251 T2079 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 619257 T2079 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 619261 T2079 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 619272 T2079 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 619276 T2079 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 619284 T2079 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 619286 T2079 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 619286 T2079 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 619287 T2079 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 619289 T2079 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 619290 T2079 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 619291 T2079 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 619292 T2079 oasc.SolrCore.<init> [onenodecollectioncore] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1372322522544/onenodecollectioncore/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372322519035/onenodecollection/
[junit4:junit4] 2> 619293 T2079 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c2a0362
[junit4:junit4] 2> 619294 T2079 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 619296 T2079 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372322519035/onenodecollection
[junit4:junit4] 2> 619297 T2079 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372322519035/onenodecollection/index/
[junit4:junit4] 2> 619297 T2079 oasc.SolrCore.initIndex WARN [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372322519035/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 619298 T2079 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372322519035/onenodecollection/index
[junit4:junit4] 2> 619300 T2079 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e9f31cf2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16f1d890),segFN=segments_1,generation=1}
[junit4:junit4] 2> 619301 T2079 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 619303 T2079 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 619303 T2079 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 619304 T2079 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 619305 T2079 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 619306 T2079 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 619306 T2079 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 619307 T2079 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 619307 T2079 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 619308 T2079 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 619310 T2079 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 619312 T2079 oass.SolrIndexSearcher.<init> Opening Searcher@9216e6f5 main
[junit4:junit4] 2> 619313 T2079 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372322519035/onenodecollection/tlog
[junit4:junit4] 2> 619314 T2079 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 619314 T2079 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 619317 T2141 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@9216e6f5 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 619319 T2079 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4] 2> 619319 T2079 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:42216/qdr/s collection:onenodecollection shard:shard1
[junit4:junit4] 2> 619320 T2079 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4] 2> 619325 T2079 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 619327 T2079 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 619327 T2079 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 619328 T2079 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:42216/qdr/s/onenodecollectioncore/
[junit4:junit4] 2> 619328 T2079 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 619329 T2079 oasc.SyncStrategy.syncToMe http://127.0.0.1:42216/qdr/s/onenodecollectioncore/ has no replicas
[junit4:junit4] 2> 619329 T2079 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:42216/qdr/s/onenodecollectioncore/
[junit4:junit4] 2> 619330 T2079 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4] 2> 619670 T2067 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 619678 T2102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 619678 T2066 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 619678 T2135 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 619678 T2086 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 619678 T2073 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 619678 T2118 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 619685 T2079 oasc.ZkController.register We are http://127.0.0.1:42216/qdr/s/onenodecollectioncore/ and leader is http://127.0.0.1:42216/qdr/s/onenodecollectioncore/
[junit4:junit4] 2> 619686 T2079 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:42216/qdr/s
[junit4:junit4] 2> 619686 T2079 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 619687 T2079 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4] 2> 619688 T2079 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 619689 T2079 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372322519035/onenodecollection&action=CREATE&version=2&numShards=1&name=onenodecollectioncore&wt=javabin&roles=none&collection=onenodecollection} status=0 QTime=1906
[junit4:junit4] 2> 619690 T2044 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4] 2> 619692 T2044 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 620694 T2044 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C789 name=collection1 org.apache.solr.core.SolrCore@72952512 url=http://127.0.0.1:37320/qdr/s/collection1 node=127.0.0.1:37320_qdr%2Fs C789_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:37320/qdr/s, state=recovering, node_name=127.0.0.1:37320_qdr%2Fs, collection=collection1, shard=shard2, core=collection1}
[junit4:junit4] 2> 620782 T2138 C789 P37320 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:53079/qdr/s/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 620783 T2138 C789 P37320 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:37320/qdr/s START replicas=[http://127.0.0.1:53079/qdr/s/collection1/] nUpdates=100
[junit4:junit4] 2> 620783 T2138 C789 P37320 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 620784 T2138 C789 P37320 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 620784 T2138 C789 P37320 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 620784 T2138 C789 P37320 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 620785 T2138 C789 P37320 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 620785 T2138 C789 P37320 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:53079/qdr/s/collection1/. core=collection1
[junit4:junit4] 2> 620786 T2138 C789 P37320 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C790 name=collection1 org.apache.solr.core.SolrCore@4d948ffb url=http://127.0.0.1:53079/qdr/s/collection1 node=127.0.0.1:53079_qdr%2Fs C790_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:53079/qdr/s, state=active, node_name=127.0.0.1:53079_qdr%2Fs, collection=collection1, shard=shard2, core=collection1, leader=true}
[junit4:junit4] 2> 620789 T2098 C790 P53079 oasc.SolrCore.execute [collection1] webapp=/qdr/s path=/get params={getVersions=100&qt=/get&distrib=false&version=2&wt=javabin} status=0 QTime=0
[junit4:junit4] 2> 620792 T2095 C790 P53079 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 620794 T2095 C790 P53079 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8774a738 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4691345a),segFN=segments_1,generation=1}
[junit4:junit4] 2> 620795 T2095 C790 P53079 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 620796 T2095 C790 P53079 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4] 2> 620796 T2095 C790 P53079 oass.SolrIndexSearcher.<init> Opening Searcher@8de6dba3 realtime
[junit4:junit4] 2> 620797 T2095 C790 P53079 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 620797 T2095 C790 P53079 oasup.LogUpdateProcessor.finish [collection1] webapp=/qdr/s path=/update params={softCommit=false&commit_end_point=true&commit=true&version=2&waitSearcher=true&wt=javabin&openSearcher=false} {commit=} 0 5
[junit4:junit4] 2> 620798 T2138 C789 P37320 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 620799 T2138 C789 P37320 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 620800 T2098 C790 P53079 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 620800 T2098 C790 P53079 oasc.SolrCore.execute [collection1] webapp=/qdr/s path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=1
[junit4:junit4] 2> 620801 T2138 C789 P37320 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 620801 T2138 C789 P37320 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 620801 T2138 C789 P37320 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 620802 T2138 C789 P37320 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 620803 T2138 C789 P37320 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 621184 T2067 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 621186 T2067 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42216/qdr/s",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:42216_qdr%2Fs_onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:42216_qdr%2Fs",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"onenodecollectioncore"}
[junit4:junit4] 2> 621190 T2067 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:37320/qdr/s",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:37320_qdr%2Fs_collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:37320_qdr%2Fs",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 621196 T2066 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 621196 T2073 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 621196 T2102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 621196 T2118 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 621197 T2086 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 621196 T2135 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 621697 T2044 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 621699 T2044 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4] 2> 621700 T2044 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 621715 T2044 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 621717 T2144 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a183786e name:ZooKeeperConnection Watcher:127.0.0.1:52176 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 621718 T2044 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4] 1> / (2)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1> /solr (7)
[junit4:junit4] 1> /solr/configs (1)
[junit4:junit4] 1> /solr/configs/conf1 (9)
[junit4:junit4] 1> /solr/configs/conf1/old_synonyms.txt (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/protwords.txt (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/stopwords.txt (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/synonyms.txt (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/schema.xml (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/currency.xml (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/open-exchange-rates.json (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "disclaimer": "This data is not real, it was synthetically created to match currency.xml. It is modeled after the data format available from openexchangerates.org. See https://openexchangerates.org/documentation for details",
[junit4:junit4] 1> "license": "http://www.apache.org/licenses/LICENSE-2.0",
[junit4:junit4] 1> "timestamp": 1332070464,
[junit4:junit4] 1>
[junit4:junit4] 1>
[junit4:junit4] 1> "IMPORTANT NOTE": "In order for tests to work, this data must be kept in sync with ./currency.xml",
[junit4:junit4] 1>
[junit4:junit4] 1>
[junit4:junit4] 1> "base": "USD",
[junit4:junit4] 1> "rates": {
[junit4:junit4] 1> "USD": 1,
[junit4:junit4] 1> "JPY": 81.29,
[junit4:junit4] 1> "EUR": 2.5,
[junit4:junit4] 1> "GBP": 0.5,
[junit4:junit4] 1> "MXN": 2.0
[junit4:junit4] 1> }
[junit4:junit4] 1> }
[junit4:junit4] 1>
[junit4:junit4] 1> /solr/configs/conf1/solrconfig.xml (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/configs/conf1/mapping-ISOLatin1Accent.txt (0)
[junit4:junit4] 1> DATA: ...supressed...
[junit4:junit4] 1> /solr/overseer (3)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1> /solr/overseer/queue (0)
[junit4:junit4] 1> /solr/overseer/collection-queue-work (0)
[junit4:junit4] 1> /solr/overseer/queue-work (0)
[junit4:junit4] 1> /solr/overseer_elect (2)
[junit4:junit4] 1> /solr/overseer_elect/leader (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"id":"89936528607739907-127.0.0.1:37238_qdr%2Fs-n_0000000000"}
[junit4:junit4] 1> /solr/overseer_elect/election (5)
[junit4:junit4] 1> /solr/overseer_elect/election/89936528607739914-127.0.0.1:49474_qdr%2Fs-n_0000000003 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89936528607739912-127.0.0.1:53079_qdr%2Fs-n_0000000002 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89936528607739907-127.0.0.1:37238_qdr%2Fs-n_0000000000 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89936528607739910-127.0.0.1:42216_qdr%2Fs-n_0000000001 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89936528607739916-127.0.0.1:37320_qdr%2Fs-n_0000000004 (0)
[junit4:junit4] 1> /solr/collections (3)
[junit4:junit4] 1> /solr/collections/control_collection (3)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"configName":"conf1"}
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect (1)
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect/shard1 (1)
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election (1)
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election/89936528607739907-127.0.0.1:37238_qdr%2Fs_collection1-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/control_collection/leaders (1)
[junit4:junit4] 1> /solr/collections/control_collection/leaders/shard1 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "base_url":"http://127.0.0.1:37238/qdr/s",
[junit4:junit4] 1> "node_name":"127.0.0.1:37238_qdr%2Fs",
[junit4:junit4] 1> "core":"collection1"}
[junit4:junit4] 1> /solr/collections/control_collection/shards (0)
[junit4:junit4] 1> /solr/collections/collection1 (3)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"configName":"conf1"}
[junit4:junit4] 1> /solr/collections/collection1/leader_elect (2)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1 (1)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election (2)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/89936528607739910-127.0.0.1:42216_qdr%2Fs_collection1-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/89936528607739914-127.0.0.1:49474_qdr%2Fs_collection1-n_0000000001 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2 (1)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2/election (2)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2/election/89936528607739916-127.0.0.1:37320_qdr%2Fs_collection1-n_0000000001 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2/election/89936528607739912-127.0.0.1:53079_qdr%2Fs_collection1-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/collection1/leaders (2)
[junit4:junit4] 1> /solr/collections/collection1/leaders/shard1 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "base_url":"http://127.0.0.1:42216/qdr/s",
[junit4:junit4] 1> "node_name":"127.0.0.1:42216_qdr%2Fs",
[junit4:junit4] 1> "core":"collection1"}
[junit4:junit4] 1> /solr/collections/collection1/leaders/shard2 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "base_url":"http://127.0.0.1:53079/qdr/s",
[junit4:junit4] 1> "node_name":"127.0.0.1:53079_qdr%2Fs",
[junit4:junit4] 1> "core":"collection1"}
[junit4:junit4] 1> /solr/collections/collection1/shards (0)
[junit4:junit4] 1> /solr/collections/onenodecollection (2)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "router":"compositeId",
[junit4:junit4] 1> "configName":"conf1"}
[junit4:junit4] 1> /solr/collections/onenodecollection/leader_elect (1)
[junit4:junit4] 1> /solr/collections/onenodecollection/leader_elect/shard1 (1)
[junit4:junit4] 1> /solr/collections/onenodecollection/leader_elect/shard1/election (1)
[junit4:junit4] 1> /solr/collections/onenodecollection/leader_elect/shard1/election/89936528607739910-127.0.0.1:42216_qdr%2Fs_onenodecollectioncore-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/onenodecollection/leaders (1)
[junit4:junit4] 1> /solr/collections/onenodecollection/leaders/shard1 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "base_url":"http://127.0.0.1:42216/qdr/s",
[junit4:junit4] 1> "node_name":"127.0.0.1:42216_qdr%2Fs",
[junit4:junit4] 1> "core":"onenodecollectioncore"}
[junit4:junit4] 1> /solr/aliases.json (0)
[junit4:junit4] 1> /solr/live_nodes (5)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:37238_qdr%2Fs (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:49474_qdr%2Fs (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:53079_qdr%2Fs (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:37320_qdr%2Fs (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:42216_qdr%2Fs (0)
[junit4:junit4] 1> /solr/clusterstate.json (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "control_collection":{
[junit4:junit4] 1> "shards":{"shard1":{
[junit4:junit4] 1> "range":"80000000-7fffffff",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "replicas":{"127.0.0.1:37238_qdr%2Fs_collection1":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:37238/qdr/s",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:37238_qdr%2Fs",
[junit4:junit4] 1> "collection":"control_collection",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "leader":"true"}}}},
[junit4:junit4] 1> "router":"compositeId"},
[junit4:junit4] 1> "onenodecollection":{
[junit4:junit4] 1> "shards":{"shard1":{
[junit4:junit4] 1> "range":"80000000-7fffffff",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "replicas":{"127.0.0.1:42216_qdr%2Fs_onenodecollectioncore":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:42216/qdr/s",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:42216_qdr%2Fs",
[junit4:junit4] 1> "roles":"none",
[junit4:junit4] 1> "collection":"onenodecollection",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "core":"onenodecollectioncore",
[junit4:junit4] 1> "leader":"true"}}}},
[junit4:junit4] 1> "router":"compositeId"},
[junit4:junit4] 1> "collection1":{
[junit4:junit4] 1> "shards":{
[junit4:junit4] 1> "shard1":{
[junit4:junit4] 1> "range":"80000000-ffffffff",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "replicas":{
[junit4:junit4] 1> "127.0.0.1:42216_qdr%2Fs_collection1":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:42216/qdr/s",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:42216_qdr%2Fs",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "leader":"true"},
[junit4:junit4] 1> "127.0.0.1:49474_qdr%2Fs_collection1":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:49474/qdr/s",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:49474_qdr%2Fs",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "core":"collection1"}}},
[junit4:junit4] 1> "shard2":{
[junit4:junit4] 1> "range":"0-7fffffff",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "replicas":{
[junit4:junit4] 1> "127.0.0.1:53079_qdr%2Fs_collection1":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:53079/qdr/s",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "node_name":"127.0.0.1:53079_qdr%2Fs",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "shard":"shard2",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "leader":"true"},
[junit4:junit4] 1> "127.0.0.1:37320_qdr%2Fs_collection1":{
[junit4:junit4] 1> "base_url":"http://127.0.0.1:37320/qdr/s",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 2> 621789 T2044 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 37238
[junit4:junit4] 2> 621790 T2044 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=-1258355980
[junit4:junit4] 2> 622704 T2067 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 622706 T2067 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:37238/qdr/s",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:37238_qdr%2Fs_collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:37238_qdr%2Fs",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 622944 T2066 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 622945 T2086 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 622945 T2102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 622945 T2135 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 622945 T2118 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 624793 T2044 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 624794 T2044 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 624797 T2044 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@b54cda35
[junit4:junit4] 2> 624803 T2044 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 624804 T2044 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 624805 T2044 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 624806 T2044 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 624808 T2044 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 624809 T2044 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 624810 T2044 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/control/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/control/data/index;done=false>>]
[junit4:junit4] 2> 624811 T2044 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/control/data/index
[junit4:junit4] 2> 624813 T2044 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/control/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/control/data;done=false>>]
[junit4:junit4] 2> 624814 T2044 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/control/data
[junit4:junit4] 2> 624815 T2067 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89936528607739907-127.0.0.1:37238_qdr%2Fs-n_0000000000) am no longer a leader.
[junit4:junit4] 2> 624815 T2102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 624815 T2118 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 624816 T2086 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 624816 T2135 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 624817 T2102 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 624817 T2118 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 624818 T2135 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 624818 T2086 oasc.Overseer.start Overseer (id=89936528607739910-127.0.0.1:42216_qdr%2Fs-n_0000000001) starting
[junit4:junit4] 2> 624822 T2146 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 624822 T2086 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 624823 T2086 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 624823 T2145 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 624824 T2145 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 624825 T2145 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:37238/qdr/s",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:37238_qdr%2Fs_collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:37238_qdr%2Fs",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 624827 T2102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 624827 T2135 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 624828 T2086 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 624827 T2118 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 624837 T2044 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/qdr/s,null}
[junit4:junit4] 2> 624890 T2044 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 42216
[junit4:junit4] 2> 624891 T2044 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=2048569871
[junit4:junit4] 2> 626116 T2066 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 626116 T2066 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 626117 T2066 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 626330 T2145 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 626331 T2145 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42216/qdr/s",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:42216_qdr%2Fs_onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:42216_qdr%2Fs",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"onenodecollectioncore"}
[junit4:junit4] 2> 626334 T2145 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42216/qdr/s",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:42216_qdr%2Fs_collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:42216_qdr%2Fs",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 626336 T2118 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 626336 T2102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 626336 T2135 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 626336 T2086 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 627895 T2044 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 627896 T2044 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 627899 T2044 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> 627901 T2044 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@2b936c08
[junit4:junit4] 2> 627907 T2044 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 627908 T2044 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 627909 T2044 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 627911 T2044 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 627913 T2044 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 627914 T2044 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 627915 T2044 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty1 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty1;done=false>>]
[junit4:junit4] 2> 627915 T2044 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty1
[junit4:junit4] 2> 627916 T2044 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty1/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty1/index;done=false>>]
[junit4:junit4] 2> 627916 T2044 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty1/index
[junit4:junit4] 2> 627917 T2044 oasc.SolrCore.close [onenodecollectioncore] CLOSING SolrCore org.apache.solr.core.SolrCore@725499d
[junit4:junit4] 2> 627921 T2044 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 627922 T2044 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 627922 T2044 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 627923 T2044 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 627923 T2044 oasc.SolrCore.closeSearcher [onenodecollectioncore] Closing main searcher on request.
[junit4:junit4] 2> 627924 T2044 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 627925 T2044 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372322519035/onenodecollection/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372322519035/onenodecollection/index;done=false>>]
[junit4:junit4] 2> 627925 T2044 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372322519035/onenodecollection/index
[junit4:junit4] 2> 627926 T2044 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372322519035/onenodecollection [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372322519035/onenodecollection;done=false>>]
[junit4:junit4] 2> 627926 T2044 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1372322519035/onenodecollection
[junit4:junit4] 2> 627927 T2145 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89936528607739910-127.0.0.1:42216_qdr%2Fs-n_0000000001) am no longer a leader.
[junit4:junit4] 2> 627928 T2102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 627928 T2135 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 627928 T2118 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 627929 T2102 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 627929 T2135 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 627929 T2118 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 627930 T2102 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 627931 T2118 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 627932 T2102 oasc.Overseer.start Overseer (id=89936528607739912-127.0.0.1:53079_qdr%2Fs-n_0000000002) starting
[junit4:junit4] 2> 627932 T2118 oasc.ShardLeaderElectionContext.shouldIBeLeader Checking if I should try and be the leader.
[junit4:junit4] 2> 627933 T2118 oasc.ShardLeaderElectionContext.shouldIBeLeader My last published State was Active, it's okay to be the leader.
[junit4:junit4] 2> 627933 T2118 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 627934 T2118 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49474/qdr/s/collection1/
[junit4:junit4] 2> 627934 T2118 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 627935 T2118 oasc.SyncStrategy.syncToMe http://127.0.0.1:49474/qdr/s/collection1/ has no replicas
[junit4:junit4] 2> 627935 T2118 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49474/qdr/s/collection1/
[junit4:junit4] 2> 627935 T2148 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 627935 T2118 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 627936 T2147 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 627937 T2147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 627938 T2147 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42216/qdr/s",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:42216_qdr%2Fs_collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:42216_qdr%2Fs",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 627940 T2147 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42216/qdr/s",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:42216_qdr%2Fs_onenodecollectioncore",
[junit4:junit4] 2> "node_name":"127.0.0.1:42216_qdr%2Fs",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"onenodecollectioncore"}
[junit4:junit4] 2> 627948 T2102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 627948 T2118 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 627948 T2135 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 627948 T2044 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/qdr/s,null}
[junit4:junit4] 2> 628000 T2044 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 53079
[junit4:junit4] 2> 628001 T2044 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=-117233923
[junit4:junit4] 2> 629003 T2044 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 629004 T2044 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 629005 T2044 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@4d948ffb
[junit4:junit4] 2> 629008 T2044 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 629008 T2044 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 629009 T2044 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 629009 T2044 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 629010 T2044 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 629011 T2044 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 629011 T2044 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty2/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty2/index;done=false>>]
[junit4:junit4] 2> 629012 T2044 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty2/index
[junit4:junit4] 2> 629012 T2044 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty2 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty2;done=false>>]
[junit4:junit4] 2> 629013 T2044 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty2
[junit4:junit4] 2> 629014 T2147 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89936528607739912-127.0.0.1:53079_qdr%2Fs-n_0000000002) am no longer a leader.
[junit4:junit4] 2> 629015 T2102 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 629015 T2102 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 629015 T2102 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 629015 T2135 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 629016 T2118 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 629017 T2135 oasc.ShardLeaderElectionContext.shouldIBeLeader Checking if I should try and be the leader.
[junit4:junit4] 2> 629017 T2118 oasc.Overseer.start Overseer (id=89936528607739914-127.0.0.1:49474_qdr%2Fs-n_0000000003) starting
[junit4:junit4] 2> 629017 T2135 oasc.ShardLeaderElectionContext.shouldIBeLeader My last published State was Active, it's okay to be the leader.
[junit4:junit4] 2> 629018 T2135 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 629018 T2135 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:37320/qdr/s/collection1/
[junit4:junit4] 2> 629019 T2135 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:37320/qdr/s START replicas=[http://127.0.0.1:53079/qdr/s/collection1/] nUpdates=100
[junit4:junit4] 2> 629019 T2135 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:37320/qdr/s DONE. We have no versions. sync failed.
[junit4:junit4] 2> 629019 T2135 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 629020 T2135 oasc.ShardLeaderElectionContext.runLeaderProcess We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4:junit4] 2> 629020 T2135 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:37320/qdr/s/collection1/
[junit4:junit4] 2> 629020 T2118 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 629020 T2151 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 629020 T2135 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 629020 T2150 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 629021 T2118 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 629023 T2150 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 629024 T2150 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53079/qdr/s",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:53079_qdr%2Fs_collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:53079_qdr%2Fs",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 629024 T2135 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 629025 T2044 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/qdr/s,null}
[junit4:junit4] 2> 629026 T2135 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 629027 T2150 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53079/qdr/s",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:53079_qdr%2Fs_collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:53079_qdr%2Fs",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 629032 T2118 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 629032 T2135 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 629078 T2044 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 49474
[junit4:junit4] 2> 629079 T2044 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=2106310151
[junit4:junit4] 2> 629228 T2086 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 629228 T2086 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 629228 T2086 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 630082 T2044 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 630083 T2044 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 630086 T2044 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1b645147
[junit4:junit4] 2> 630092 T2044 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 630093 T2044 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 630094 T2044 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 630095 T2044 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 630095 T2044 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 630096 T2044 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 630096 T2044 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty3/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty3/index;done=false>>]
[junit4:junit4] 2> 630097 T2044 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty3/index
[junit4:junit4] 2> 630097 T2044 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty3 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty3;done=false>>]
[junit4:junit4] 2> 630098 T2044 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty3
[junit4:junit4] 2> 630099 T2150 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89936528607739914-127.0.0.1:49474_qdr%2Fs-n_0000000003) am no longer a leader.
[junit4:junit4] 2> 630099 T2118 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 630100 T2135 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 630102 T2135 oasc.Overseer.start Overseer (id=89936528607739916-127.0.0.1:37320_qdr%2Fs-n_0000000004) starting
[junit4:junit4] 2> 630106 T2135 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 630106 T2153 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 630106 T2152 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 630107 T2135 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4:junit4] 2> 630108 T2152 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 630108 T2152 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49474/qdr/s",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:49474_qdr%2Fs_collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:49474_qdr%2Fs",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 630111 T2152 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49474/qdr/s",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:49474_qdr%2Fs_collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:49474_qdr%2Fs",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "core":"collection1"}
[junit4:junit4] 2> 630113 T2135 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 630121 T2044 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/qdr/s,null}
[junit4:junit4] 2> 630174 T2044 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 37320
[junit4:junit4] 2> 630175 T2044 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=-762702526
[junit4:junit4] 2> 631177 T2044 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 631178 T2044 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 631181 T2044 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@72952512
[junit4:junit4] 2> 631188 T2044 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 631189 T2044 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 631190 T2044 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 631191 T2044 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 631194 T2044 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 631195 T2044 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 631196 T2044 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty4/index;done=false>>]
[junit4:junit4] 2> 631196 T2044 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty4/index
[junit4:junit4] 2> 631197 T2044 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty4 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty4;done=false>>]
[junit4:junit4] 2> 631198 T2044 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1372322519035/jetty4
[junit4:junit4] 2> 631199 T2152 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89936528607739916-127.0.0.1:37320_qdr%2Fs-n_0000000004) am no longer a leader.
[junit4:junit4] 2> 631200 T2135 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 631222 T2044 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/qdr/s,null}
[junit4:junit4] 2> 631279 T2044 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 631281 T2044 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:52176 52176
[junit4:junit4] 1> "node_name":"127.0.0.1:37320_qdr%2Fs",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "shard":"shard2",
[junit4:junit4] 1> "core":"collection1"}}}},
[junit4:junit4] 1> "router":"compositeId"}}
[junit4:junit4] 1> /zookeeper (1)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1>
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZk2Test -Dtests.method=testDistribSearch -Dtests.seed=8710E3543D9C6EA8 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=de_LU_PREEURO -Dtests.timezone=Australia/Canberra -Dtests.file.encoding=UTF-8
[junit4:junit4] ERROR 28.7s J1 | BasicDistributedZk2Test.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:53079/qdr/s/onenodecollectioncore returned non ok status:404, message:Can not find: /qdr/s/onenodecollectioncore/update
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([8710E3543D9C6EA8:6F66D4C4AC30E94]:0)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4:junit4] > at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
[junit4:junit4] > at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
[junit4:junit4] > at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
[junit4:junit4] > at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:198)
[junit4:junit4] > at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:90)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:780)
[junit4:junit4] 2> 631294 T2044 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 28696 T2043 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 4 leaked thread(s).
[junit4:junit4] 2> 631400 T2118 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 631401 T2118 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 632501 T2135 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 632501 T2135 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=de_LU_PREEURO, timezone=Australia/Canberra
[junit4:junit4] 2> NOTE: Linux 3.2.0-48-generic x86/IBM Corporation 1.7.0 (32-bit)/cpus=8,threads=2,free=45113336,total=218693632
[junit4:junit4] 2> NOTE: All tests run in this JVM: [SolrCoreCheckLockOnStartupTest, IndexReaderFactoryTest, TestIndexingPerformance, DocValuesMultiTest, SimplePostToolTest, ChaosMonkeySafeLeaderTest, NoCacheHeaderTest, HardAutoCommitTest, TestReloadAndDeleteDocs, DefaultValueUpdateProcessorTest, TestCollationKeyRangeQueries, SolrPluginUtilsTest, ZkSolrClientTest, TestLMJelinekMercerSimilarityFactory, XsltUpdateRequestHandlerTest, TestSolr4Spatial, TestMergePolicyConfig, RequestHandlersTest, TestUniqueKeyFieldResource, TestSystemIdResolver, FieldAnalysisRequestHandlerTest, SpellCheckComponentTest, DistanceFunctionTest, IndexSchemaRuntimeFieldTest, CurrencyFieldOpenExchangeTest, SpellPossibilityIteratorTest, TestRecovery, UpdateParamsTest, TestDistributedGrouping, CopyFieldTest, TestMultiCoreConfBootstrap, OpenCloseCoreStressTest, CollectionsAPIDistributedZkTest, DateMathParserTest, ZkNodePropsTest, TestBinaryResponseWriter, SuggesterTSTTest, TestJmxIntegration, SolrTestCaseJ4Test, TestDynamicFieldCollectionResource, TestArbitraryIndexDir, ConvertedLegacyTest, TestDefaultSearchFieldResource, DebugComponentTest, TestLazyCores, TestZkChroot, OpenExchangeRatesOrgProviderTest, TestHashPartitioner, SolrIndexConfigTest, TestCodecSupport, TestCoreDiscovery, SuggesterWFSTTest, TimeZoneUtilsTest, TestWordDelimiterFilterFactory, TestUtils, TestBinaryField, EchoParamsTest, TestComponentsName, MultiTermTest, TestDFRSimilarityFactory, FileUtilsTest, TestDistributedSearch, NotRequiredUniqueKeyTest, TestIndexSearcher, TestRangeQuery, TestSchemaResource, BasicZkTest, SolrCmdDistributorTest, TestReload, BasicDistributedZk2Test]
[junit4:junit4] Completed on J1 in 29.98s, 1 test, 1 error <<< FAILURES!
[...truncated 458 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:392: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:385: 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/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:437: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1246: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:890: There were test failures: 299 suites, 1289 tests, 1 error, 14 ignored (8 assumptions)
Total time: 39 minutes 34 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure