lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Mark Miller <markrmil...@gmail.com>
Subject Re: [JENKINS] Lucene-Solr-Tests-4.x-java7 - Build # 858 - Failure
Date Fri, 04 Jan 2013 18:18:03 GMT
Right - the particular failure is only on freebsd - and its really a test setup issue that i have not had a chance too look into.

We explicitly try to setup a bad situation by skipping some nodes when sending from leader to replicas, and then check that the bad situation is setup - but its not detecting the bad situation. I've tried to address this in the past, but I still don't know how/why its happening. It doesnt always happen and it's pretty weird.

- Mark

On Jan 4, 2013, at 1:11 PM, Uwe Schindler <uwe@thetaphi.de> wrote:

> Sorry,
> 
> SyncSliceTest fails on other platforms, but with different stack traces!
> 
> Uwe
> 
> -----
> Uwe Schindler
> H.-H.-Meier-Allee 63, D-28213 Bremen
> http://www.thetaphi.de
> eMail: uwe@thetaphi.de
> 
> 
>> -----Original Message-----
>> From: Uwe Schindler [mailto:uwe@thetaphi.de]
>> Sent: Friday, January 04, 2013 7:08 PM
>> To: dev@lucene.apache.org
>> Subject: RE: [JENKINS] Lucene-Solr-Tests-4.x-java7 - Build # 858 - Failure
>> 
>> Also fails on MacOSX (which is BSD, too) and Linux! Just look into Policeman
>> Jenkins failures.
>> 
>> Uwe
>> 
>> -----
>> Uwe Schindler
>> H.-H.-Meier-Allee 63, D-28213 Bremen
>> http://www.thetaphi.de
>> eMail: uwe@thetaphi.de
>> 
>> 
>>> -----Original Message-----
>>> From: yseeley@gmail.com [mailto:yseeley@gmail.com] On Behalf Of Yonik
>>> Seeley
>>> Sent: Friday, January 04, 2013 7:05 PM
>>> To: dev@lucene.apache.org
>>> Subject: Re: [JENKINS] Lucene-Solr-Tests-4.x-java7 - Build # 858 - Failure
>>> 
>>> Are all these SyncSliceTest failures on BSD?
>>> If so, and if it's not immediately apparent what the issue is, we
>>> should perhaps disable for BSD/blackhole only and move on...
>>> 
>>> -Yonik
>>> http://lucidworks.com
>>> 
>>> 
>>> On Fri, Jan 4, 2013 at 10:17 AM, Apache Jenkins Server
>>> <jenkins@builds.apache.org> wrote:
>>>> Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-java7/858/
>>>> 
>>>> 1 tests failed.
>>>> REGRESSION:  org.apache.solr.cloud.SyncSliceTest.testDistribSearch
>>>> 
>>>> Error Message:
>>>> shard1 should have just been set up to be inconsistent - but it's still
>>> consistent
>>>> 
>>>> Stack Trace:
>>>> java.lang.AssertionError: shard1 should have just been set up to be
>>> inconsistent - but it's still consistent
>>>>        at
>>> 
>> __randomizedtesting.SeedInfo.seed([AFD4F4538756AB5B:2E327A4BF009CB6
>>> 7]:0)
>>>>        at org.junit.Assert.fail(Assert.java:93)
>>>>        at org.junit.Assert.assertTrue(Assert.java:43)
>>>>        at org.junit.Assert.assertNotNull(Assert.java:526)
>>>>        at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:214)
>>>>        at
>>> 
>> org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistri
>>> butedSearchTestCase.java:794)
>>>>        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>>>>        at
>>> 
>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.j
>>> ava:57)
>>>>        at
>>> 
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces
>>> sorImpl.java:43)
>>>>        at java.lang.reflect.Method.invoke(Method.java:601)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomize
>>> dRunner.java:1559)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(Rando
>>> mizedRunner.java:79)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Rando
>>> mizedRunner.java:737)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Rando
>>> mizedRunner.java:773)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Rando
>>> mizedRunner.java:787)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.
>>> evaluate(SystemPropertiesRestoreRule.java:53)
>>>>        at
>>> 
>> org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRule
>>> SetupTeardownChained.java:50)
>>>>        at
>>> 
>> org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCa
>>> cheSanity.java:51)
>>>>        at
>>> 
>> org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeA
>>> fterRule.java:46)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1
>>> .evaluate(SystemPropertiesInvariantRule.java:55)
>>>>        at
>>> 
>> org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleTh
>>> readAndTestName.java:49)
>>>>        at
>>> 
>> org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRule
>>> IgnoreAfterMaxFailures.java:70)
>>>>        at
>>> 
>> org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure
>>> .java:48)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(Stat
>>> ementAdapter.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(ThreadL
>>> eakControl.java:442)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran
>>> domizedRunner.java:746)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(Rando
>>> mizedRunner.java:648)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(Rando
>>> mizedRunner.java:682)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Rando
>>> mizedRunner.java:693)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(Stat
>>> ementAdapter.java:36)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.
>>> evaluate(SystemPropertiesRestoreRule.java:53)
>>>>        at
>>> 
>> org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeA
>>> fterRule.java:46)
>>>>        at
>>> 
>> org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreCl
>>> assName.java:42)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1
>>> .evaluate(SystemPropertiesInvariantRule.java:55)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMet
>>> hodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMet
>>> hodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(Stat
>>> ementAdapter.java:36)
>>>>        at
>>> 
>> org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAss
>>> ertionsRequired.java:43)
>>>>        at
>>> 
>> org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure
>>> .java:48)
>>>>        at
>>> 
>> org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRule
>>> IgnoreAfterMaxFailures.java:70)
>>>>        at
>>> 
>> org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnore
>>> TestSuites.java:55)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(Stat
>>> ementAdapter.java:36)
>>>>        at
>>> 
>> com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.
>>> run(ThreadLeakControl.java:358)
>>>>        at java.lang.Thread.run(Thread.java:722)
>>>> 
>>>> 
>>>> 
>>>> 
>>>> Build Log:
>>>> [...truncated 9150 lines...]
>>>> [junit4:junit4] Suite: org.apache.solr.cloud.SyncSliceTest
>>>> [junit4:junit4]   2> 0 T2684
>>> oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext
>>> system property: /jxf/db
>>>> [junit4:junit4]   2> 4 T2684 oas.SolrTestCaseJ4.setUp ###Starting
>>> testDistribSearch
>>>> [junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./solrtest-SyncSliceTest-1357312117664
>>>> [junit4:junit4]   2> 6 T2684 oasc.ZkTestServer.run STARTING ZK TEST
>> SERVER
>>>> [junit4:junit4]   2> 6 T2685
>> oasc.ZkTestServer$ZKServerMain.runFromConfig
>>> Starting server
>>>> [junit4:junit4]   2> 9 T2685 oazs.ZooKeeperServer.setTickTime tickTime
>> set
>>> to 1000
>>>> [junit4:junit4]   2> 9 T2685 oazs.ZooKeeperServer.setMinSessionTimeout
>>> minSessionTimeout set to -1
>>>> [junit4:junit4]   2> 9 T2685 oazs.ZooKeeperServer.setMaxSessionTimeout
>>> maxSessionTimeout set to -1
>>>> [junit4:junit4]   2> 9 T2685 oazs.NIOServerCnxnFactory.configure binding
>> to
>>> port 0.0.0.0/0.0.0.0:0
>>>> [junit4:junit4]   2> 10 T2685 oazsp.FileTxnSnapLog.save Snapshotting: 0x0
>> to
>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/zookeeper/server1/data/version-2/snapshot.0
>>>> [junit4:junit4]   2> 107 T2684 oasc.ZkTestServer.run start zk server on
>>> port:24224
>>>> [junit4:junit4]   2> 107 T2684 oaz.ZooKeeper.<init> Initiating client
>>> connection, connectString=127.0.0.1:24224 sessionTimeout=10000
>>> watcher=org.apache.solr.common.cloud.ConnectionManager@20d73428
>>>> [junit4:junit4]   2> 108 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Waiting for client to connect to ZooKeeper
>>>> [junit4:junit4]   2> 109 T2690 oaz.ClientCnxn$SendThread.logStartConnect
>>> Opening socket connection to server localhost/127.0.0.1:24224. Will not
>>> attempt to authenticate using SASL (access denied
>>> ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
>>>> [junit4:junit4]   2> 109 T2690
>> oaz.ClientCnxn$SendThread.primeConnection
>>> Socket connection established to localhost/127.0.0.1:24224, initiating
>> session
>>>> [junit4:junit4]   2> 110 T2686 oazs.NIOServerCnxnFactory.run Accepted
>>> socket connection from /140.211.11.196:36409
>>>> [junit4:junit4]   2> 110 T2686
>>> oazs.ZooKeeperServer.processConnectRequest Client attempting to
>>> establish new session at /140.211.11.196:36409
>>>> [junit4:junit4]   2> 111 T2688 oazsp.FileTxnLog.append Creating new log
>> file:
>>> log.1
>>>> [junit4:junit4]   2> 113 T2688 oazs.ZooKeeperServer.finishSessionInit
>>> Established session 0x13c061b4ba60000 with negotiated timeout 10000 for
>>> client /140.211.11.196:36409
>>>> [junit4:junit4]   2> 113 T2690 oaz.ClientCnxn$SendThread.onConnected
>>> Session establishment complete on server localhost/127.0.0.1:24224,
>>> sessionid = 0x13c061b4ba60000, negotiated timeout = 10000
>>>> [junit4:junit4]   2> 114 T2691 oascc.ConnectionManager.process Watcher
>>> org.apache.solr.common.cloud.ConnectionManager@20d73428
>>> name:ZooKeeperConnection Watcher:127.0.0.1:24224 got event
>>> WatchedEvent state:SyncConnected type:None path:null path:null
>>> type:None
>>>> [junit4:junit4]   2> 114 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Client is connected to ZooKeeper
>>>> [junit4:junit4]   2> 114 T2684 oascc.SolrZkClient.makePath makePath: /solr
>>>> [junit4:junit4]   2> 118 T2689 oazs.PrepRequestProcessor.pRequest2Txn
>>> Processed session termination for sessionid: 0x13c061b4ba60000
>>>> [junit4:junit4]   2> 120 T2691 oaz.ClientCnxn$EventThread.run
>> EventThread
>>> shut down
>>>> [junit4:junit4]   2> 121 T2686 oazs.NIOServerCnxn.closeSock Closed
>> socket
>>> connection for client /140.211.11.196:36409 which had sessionid
>>> 0x13c061b4ba60000
>>>> [junit4:junit4]   2> 120 T2684 oaz.ZooKeeper.close Session:
>>> 0x13c061b4ba60000 closed
>>>> [junit4:junit4]   2> 121 T2684 oaz.ZooKeeper.<init> Initiating client
>>> connection, connectString=127.0.0.1:24224/solr sessionTimeout=10000
>>> watcher=org.apache.solr.common.cloud.ConnectionManager@3d14ef
>>>> [junit4:junit4]   2> 122 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Waiting for client to connect to ZooKeeper
>>>> [junit4:junit4]   2> 122 T2692 oaz.ClientCnxn$SendThread.logStartConnect
>>> Opening socket connection to server localhost/127.0.0.1:24224. Will not
>>> attempt to authenticate using SASL (access denied
>>> ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
>>>> [junit4:junit4]   2> 123 T2692
>> oaz.ClientCnxn$SendThread.primeConnection
>>> Socket connection established to localhost/127.0.0.1:24224, initiating
>> session
>>>> [junit4:junit4]   2> 123 T2686 oazs.NIOServerCnxnFactory.run Accepted
>>> socket connection from /140.211.11.196:64990
>>>> [junit4:junit4]   2> 123 T2686
>>> oazs.ZooKeeperServer.processConnectRequest Client attempting to
>>> establish new session at /140.211.11.196:64990
>>>> [junit4:junit4]   2> 125 T2688 oazs.ZooKeeperServer.finishSessionInit
>>> Established session 0x13c061b4ba60001 with negotiated timeout 10000 for
>>> client /140.211.11.196:64990
>>>> [junit4:junit4]   2> 125 T2692 oaz.ClientCnxn$SendThread.onConnected
>>> Session establishment complete on server localhost/127.0.0.1:24224,
>>> sessionid = 0x13c061b4ba60001, negotiated timeout = 10000
>>>> [junit4:junit4]   2> 126 T2693 oascc.ConnectionManager.process Watcher
>>> org.apache.solr.common.cloud.ConnectionManager@3d14ef
>>> name:ZooKeeperConnection Watcher:127.0.0.1:24224/solr got event
>>> WatchedEvent state:SyncConnected type:None path:null path:null
>>> type:None
>>>> [junit4:junit4]   2> 126 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Client is connected to ZooKeeper
>>>> [junit4:junit4]   2> 127 T2684 oascc.SolrZkClient.makePath makePath:
>>> /collections/collection1
>>>> [junit4:junit4]   2> 137 T2684 oascc.SolrZkClient.makePath makePath:
>>> /collections/collection1/shards
>>>> [junit4:junit4]   2> 140 T2684 oascc.SolrZkClient.makePath makePath:
>>> /collections/control_collection
>>>> [junit4:junit4]   2> 149 T2684 oascc.SolrZkClient.makePath makePath:
>>> /collections/control_collection/shards
>>>> [junit4:junit4]   2> 153 T2684 oasc.AbstractZkTestCase.putConfig put
>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to
>>> /configs/conf1/solrconfig.xml
>>>> [junit4:junit4]   2> 154 T2684 oascc.SolrZkClient.makePath makePath:
>>> /configs/conf1/solrconfig.xml
>>>> [junit4:junit4]   2> 160 T2684 oasc.AbstractZkTestCase.putConfig put
>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to
>>> /configs/conf1/schema.xml
>>>> [junit4:junit4]   2> 161 T2684 oascc.SolrZkClient.makePath makePath:
>>> /configs/conf1/schema.xml
>>>> [junit4:junit4]   2> 273 T2684 oasc.AbstractZkTestCase.putConfig put
>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to
>>> /configs/conf1/stopwords.txt
>>>> [junit4:junit4]   2> 274 T2684 oascc.SolrZkClient.makePath makePath:
>>> /configs/conf1/stopwords.txt
>>>> [junit4:junit4]   2> 277 T2684 oasc.AbstractZkTestCase.putConfig put
>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to
>>> /configs/conf1/protwords.txt
>>>> [junit4:junit4]   2> 278 T2684 oascc.SolrZkClient.makePath makePath:
>>> /configs/conf1/protwords.txt
>>>> [junit4:junit4]   2> 281 T2684 oasc.AbstractZkTestCase.putConfig put
>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to
>>> /configs/conf1/currency.xml
>>>> [junit4:junit4]   2> 281 T2684 oascc.SolrZkClient.makePath makePath:
>>> /configs/conf1/currency.xml
>>>> [junit4:junit4]   2> 285 T2684 oasc.AbstractZkTestCase.putConfig put
>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-
>>> rates.json to /configs/conf1/open-exchange-rates.json
>>>> [junit4:junit4]   2> 285 T2684 oascc.SolrZkClient.makePath makePath:
>>> /configs/conf1/open-exchange-rates.json
>>>> [junit4:junit4]   2> 290 T2684 oasc.AbstractZkTestCase.putConfig put
>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-
>>> ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
>>>> [junit4:junit4]   2> 292 T2684 oascc.SolrZkClient.makePath makePath:
>>> /configs/conf1/mapping-ISOLatin1Accent.txt
>>>> [junit4:junit4]   2> 295 T2684 oasc.AbstractZkTestCase.putConfig put
>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build/solr-core/test-
>> files/solr/collection1/conf/old_synonyms.txt
>>> to /configs/conf1/old_synonyms.txt
>>>> [junit4:junit4]   2> 295 T2684 oascc.SolrZkClient.makePath makePath:
>>> /configs/conf1/old_synonyms.txt
>>>> [junit4:junit4]   2> 298 T2684 oasc.AbstractZkTestCase.putConfig put
>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to
>>> /configs/conf1/synonyms.txt
>>>> [junit4:junit4]   2> 299 T2684 oascc.SolrZkClient.makePath makePath:
>>> /configs/conf1/synonyms.txt
>>>> [junit4:junit4]   2> 302 T2689 oazs.PrepRequestProcessor.pRequest2Txn
>>> Processed session termination for sessionid: 0x13c061b4ba60001
>>>> [junit4:junit4]   2> 309 T2693 oaz.ClientCnxn$EventThread.run
>> EventThread
>>> shut down
>>>> [junit4:junit4]   2> 309 T2684 oaz.ZooKeeper.close Session:
>>> 0x13c061b4ba60001 closed
>>>> [junit4:junit4]   2> 309 T2686 oazs.NIOServerCnxn.closeSock Closed
>> socket
>>> connection for client /140.211.11.196:64990 which had sessionid
>>> 0x13c061b4ba60001
>>>> [junit4:junit4]   2> 475 T2684 oejs.Server.doStart jetty-8.1.8.v20121106
>>>> [junit4:junit4]   2> 483 T2684 oejs.AbstractConnector.doStart Started
>>> SocketConnector@127.0.0.1:25950
>>>> [junit4:junit4]   2> 484 T2684 oasc.SolrResourceLoader.locateSolrHome
>> JNDI
>>> not configured for solr (NoInitialContextEx)
>>>> [junit4:junit4]   2> 485 T2684 oasc.SolrResourceLoader.locateSolrHome
>>> using system property solr.solr.home: /usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-
>>> 1357312117969
>>>> [junit4:junit4]   2> 486 T2684 oasc.SolrResourceLoader.<init> new
>>> SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-
>>> 1357312117969/'
>>>> [junit4:junit4]   2> 531 T2684 oass.SolrDispatchFilter.init
>>> SolrDispatchFilter.init()
>>>> [junit4:junit4]   2> 531 T2684 oasc.SolrResourceLoader.locateSolrHome
>> JNDI
>>> not configured for solr (NoInitialContextEx)
>>>> [junit4:junit4]   2> 532 T2684 oasc.SolrResourceLoader.locateSolrHome
>>> using system property solr.solr.home: /usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-
>>> 1357312117969
>>>> [junit4:junit4]   2> 533 T2684 oasc.CoreContainer$Initializer.initialize
>> looking
>>> for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-
>>> 1357312117969/solr.xml
>>>> [junit4:junit4]   2> 533 T2684 oasc.CoreContainer.<init> New
>> CoreContainer
>>> 800607924
>>>> [junit4:junit4]   2> 534 T2684 oasc.CoreContainer.load Loading
>>> CoreContainer using Solr Home: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-
>>> 1357312117969/'
>>>> [junit4:junit4]   2> 534 T2684 oasc.SolrResourceLoader.<init> new
>>> SolrResourceLoader for directory: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-
>>> 1357312117969/'
>>>> [junit4:junit4]   2> 566 T2684
>> oashc.HttpShardHandlerFactory.getParameter
>>> Setting socketTimeout to: 30000
>>>> [junit4:junit4]   2> 567 T2684
>> oashc.HttpShardHandlerFactory.getParameter
>>> Setting urlScheme to: http://
>>>> [junit4:junit4]   2> 567 T2684
>> oashc.HttpShardHandlerFactory.getParameter
>>> Setting connTimeout to: 15000
>>>> [junit4:junit4]   2> 568 T2684
>> oashc.HttpShardHandlerFactory.getParameter
>>> Setting maxConnectionsPerHost to: 20
>>>> [junit4:junit4]   2> 568 T2684
>> oashc.HttpShardHandlerFactory.getParameter
>>> Setting corePoolSize to: 0
>>>> [junit4:junit4]   2> 569 T2684
>> oashc.HttpShardHandlerFactory.getParameter
>>> Setting maximumPoolSize to: 2147483647
>>>> [junit4:junit4]   2> 569 T2684
>> oashc.HttpShardHandlerFactory.getParameter
>>> Setting maxThreadIdleTime to: 5
>>>> [junit4:junit4]   2> 570 T2684
>> oashc.HttpShardHandlerFactory.getParameter
>>> Setting sizeOfQueue to: -1
>>>> [junit4:junit4]   2> 570 T2684
>> oashc.HttpShardHandlerFactory.getParameter
>>> Setting fairnessPolicy to: false
>>>> [junit4:junit4]   2> 571 T2684 oascsi.HttpClientUtil.createClient Creating
>> new
>>> http client,
>>> 
>> config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout
>>> =30000&connTimeout=15000&retry=false
>>>> [junit4:junit4]   2> 593 T2684 oasc.CoreContainer.load Registering Log
>>> Listener
>>>> [junit4:junit4]   2> 613 T2684 oasc.CoreContainer.initZooKeeper
>> Zookeeper
>>> client=127.0.0.1:24224/solr
>>>> [junit4:junit4]   2> 613 T2684 oasc.ZkController.checkChrootPath zkHost
>>> includes chroot
>>>> [junit4:junit4]   2> 614 T2684 oaz.ZooKeeper.<init> Initiating client
>>> connection, connectString=127.0.0.1:24224 sessionTimeout=60000
>>> watcher=org.apache.solr.common.cloud.ConnectionManager@70c6f910
>>>> [junit4:junit4]   2> 615 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Waiting for client to connect to ZooKeeper
>>>> [junit4:junit4]   2> 615 T2703 oaz.ClientCnxn$SendThread.logStartConnect
>>> Opening socket connection to server localhost/127.0.0.1:24224. Will not
>>> attempt to authenticate using SASL (access denied
>>> ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
>>>> [junit4:junit4]   2> 616 T2703
>> oaz.ClientCnxn$SendThread.primeConnection
>>> Socket connection established to localhost/127.0.0.1:24224, initiating
>> session
>>>> [junit4:junit4]   2> 616 T2686 oazs.NIOServerCnxnFactory.run Accepted
>>> socket connection from /140.211.11.196:20113
>>>> [junit4:junit4]   2> 617 T2686
>>> oazs.ZooKeeperServer.processConnectRequest Client attempting to
>>> establish new session at /140.211.11.196:20113
>>>> [junit4:junit4]   2> 619 T2688 oazs.ZooKeeperServer.finishSessionInit
>>> Established session 0x13c061b4ba60002 with negotiated timeout 20000 for
>>> client /140.211.11.196:20113
>>>> [junit4:junit4]   2> 619 T2703 oaz.ClientCnxn$SendThread.onConnected
>>> Session establishment complete on server localhost/127.0.0.1:24224,
>>> sessionid = 0x13c061b4ba60002, negotiated timeout = 20000
>>>> [junit4:junit4]   2> 619 T2704 oascc.ConnectionManager.process Watcher
>>> org.apache.solr.common.cloud.ConnectionManager@70c6f910
>>> name:ZooKeeperConnection Watcher:127.0.0.1:24224 got event
>>> WatchedEvent state:SyncConnected type:None path:null path:null
>>> type:None
>>>> [junit4:junit4]   2> 619 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Client is connected to ZooKeeper
>>>> [junit4:junit4]   2> 621 T2689 oazs.PrepRequestProcessor.pRequest2Txn
>>> Processed session termination for sessionid: 0x13c061b4ba60002
>>>> [junit4:junit4]   2> 622 T2704 oaz.ClientCnxn$EventThread.run
>> EventThread
>>> shut down
>>>> [junit4:junit4]   2> 622 T2686 oazs.NIOServerCnxn.closeSock Closed
>> socket
>>> connection for client /140.211.11.196:20113 which had sessionid
>>> 0x13c061b4ba60002
>>>> [junit4:junit4]   2> 622 T2684 oaz.ZooKeeper.close Session:
>>> 0x13c061b4ba60002 closed
>>>> [junit4:junit4]   2> 622 T2684 oascsi.HttpClientUtil.createClient Creating
>> new
>>> http client,
>>> 
>> config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=
>>> 15000&connTimeout=30000
>>>> [junit4:junit4]   2> 634 T2684 oaz.ZooKeeper.<init> Initiating client
>>> connection, connectString=127.0.0.1:24224/solr sessionTimeout=30000
>>> watcher=org.apache.solr.common.cloud.ConnectionManager@6f66a816
>>>> [junit4:junit4]   2> 635 T2705 oaz.ClientCnxn$SendThread.logStartConnect
>>> Opening socket connection to server localhost/127.0.0.1:24224. Will not
>>> attempt to authenticate using SASL (access denied
>>> ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
>>>> [junit4:junit4]   2> 635 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Waiting for client to connect to ZooKeeper
>>>> [junit4:junit4]   2> 635 T2705
>> oaz.ClientCnxn$SendThread.primeConnection
>>> Socket connection established to localhost/127.0.0.1:24224, initiating
>> session
>>>> [junit4:junit4]   2> 635 T2686 oazs.NIOServerCnxnFactory.run Accepted
>>> socket connection from /140.211.11.196:57711
>>>> [junit4:junit4]   2> 636 T2686
>>> oazs.ZooKeeperServer.processConnectRequest Client attempting to
>>> establish new session at /140.211.11.196:57711
>>>> [junit4:junit4]   2> 638 T2688 oazs.ZooKeeperServer.finishSessionInit
>>> Established session 0x13c061b4ba60003 with negotiated timeout 20000 for
>>> client /140.211.11.196:57711
>>>> [junit4:junit4]   2> 638 T2705 oaz.ClientCnxn$SendThread.onConnected
>>> Session establishment complete on server localhost/127.0.0.1:24224,
>>> sessionid = 0x13c061b4ba60003, negotiated timeout = 20000
>>>> [junit4:junit4]   2> 639 T2706 oascc.ConnectionManager.process Watcher
>>> org.apache.solr.common.cloud.ConnectionManager@6f66a816
>>> name:ZooKeeperConnection Watcher:127.0.0.1:24224/solr got event
>>> WatchedEvent state:SyncConnected type:None path:null path:null
>>> type:None
>>>> [junit4:junit4]   2> 639 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Client is connected to ZooKeeper
>>>> [junit4:junit4]   2> 694 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60003
>>> type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer Error:KeeperErrorCode = NodeExists for
>> /solr/overseer
>>>> [junit4:junit4]   2> 729 T2684 oascc.SolrZkClient.makePath makePath:
>>> /live_nodes
>>>> [junit4:junit4]   2> 736 T2684 oasc.ZkController.createEphemeralLiveNode
>>> Register node as live in ZooKeeper:/live_nodes/127.0.0.1:25950_jxf%2Fdb
>>>> [junit4:junit4]   2> 737 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60003
>>> type:delete cxid:0x7 zxid:0x1c txntype:-1 reqpath:n/a Error
>>> Path:/solr/live_nodes/127.0.0.1:25950_jxf%2Fdb Error:KeeperErrorCode =
>>> NoNode for /solr/live_nodes/127.0.0.1:25950_jxf%2Fdb
>>>> [junit4:junit4]   2> 762 T2684 oascc.SolrZkClient.makePath makePath:
>>> /live_nodes/127.0.0.1:25950_jxf%2Fdb
>>>> [junit4:junit4]   2> 765 T2684 oascc.SolrZkClient.makePath makePath:
>>> /overseer_elect/election
>>>> [junit4:junit4]   2> 820 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60003
>>> type:delete cxid:0x15 zxid:0x21 txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for
>>> /solr/overseer_elect/leader
>>>> [junit4:junit4]   2> 858 T2684 oascc.SolrZkClient.makePath makePath:
>>> /overseer_elect/leader
>>>> [junit4:junit4]   2> 861 T2684 oasc.Overseer.start Overseer
>>> (id=88952806943621123-127.0.0.1:25950_jxf%2Fdb-n_0000000000) starting
>>>> [junit4:junit4]   2> 861 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60003
>>> type:create cxid:0x1a zxid:0x23 txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer Error:KeeperErrorCode = NodeExists for
>> /solr/overseer
>>>> [junit4:junit4]   2> 867 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60003
>>> type:create cxid:0x1b zxid:0x24 txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer Error:KeeperErrorCode = NodeExists for
>> /solr/overseer
>>>> [junit4:junit4]   2> 868 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60003
>>> type:create cxid:0x1c zxid:0x25 txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer Error:KeeperErrorCode = NodeExists for
>> /solr/overseer
>>>> [junit4:junit4]   2> 876 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60003
>>> type:create cxid:0x1d zxid:0x26 txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer Error:KeeperErrorCode = NodeExists for
>> /solr/overseer
>>>> [junit4:junit4]   2> 878 T2708 oasc.OverseerCollectionProcessor.run
>> Process
>>> current queue of collection messages
>>>> [junit4:junit4]   2> 879 T2684 oascc.SolrZkClient.makePath makePath:
>>> /clusterstate.json
>>>> [junit4:junit4]   2> 887 T2684
>>> oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating
>>> cluster state from ZooKeeper...
>>>> [junit4:junit4]   2> 889 T2707 oasc.Overseer$ClusterStateUpdater.run
>>> Starting to work on the main queue
>>>> [junit4:junit4]   2> 893 T2709 oasc.CoreContainer.create Creating SolrCore
>>> 'collection1' using instanceDir: /usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-
>>> 1357312117969/collection1
>>>> [junit4:junit4]   2> 894 T2709 oasc.ZkController.createCollectionZkNode
>>> Check for collection zkNode:control_collection
>>>> [junit4:junit4]   2> 894 T2709 oasc.ZkController.createCollectionZkNode
>>> Collection zkNode exists
>>>> [junit4:junit4]   2> 894 T2709 oasc.ZkController.readConfigName Load
>>> collection config from:/collections/control_collection
>>>> [junit4:junit4]   2> 896 T2709 oasc.SolrResourceLoader.<init> new
>>> SolrResourceLoader for directory: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-
>>> 1357312117969/collection1/'
>>>> [junit4:junit4]   2> 897 T2709 oasc.SolrResourceLoader.replaceClassLoader
>>> Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/org.apache.solr.cloud.SyncSliceTest-controljetty-
>>> 1357312117969/collection1/lib/classes/' to classloader
>>>> [junit4:junit4]   2> 897 T2709 oasc.SolrResourceLoader.replaceClassLoader
>>> Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/org.apache.solr.cloud.SyncSliceTest-controljetty-
>>> 1357312117969/collection1/lib/README' to classloader
>>>> [junit4:junit4]   2> 955 T2709 oasc.SolrConfig.<init> Using Lucene
>>> MatchVersion: LUCENE_41
>>>> [junit4:junit4]   2> 1003 T2709 oasc.SolrConfig.<init> Loaded SolrConfig:
>>> solrconfig.xml
>>>> [junit4:junit4]   2> 1104 T2709 oass.IndexSchema.readSchema Reading
>> Solr
>>> Schema
>>>> [junit4:junit4]   2> 1108 T2709 oass.IndexSchema.readSchema Schema
>>> name=test
>>>> [junit4:junit4]   2> 1524 T2709 oass.OpenExchangeRatesOrgProvider.init
>>> Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>>>> [junit4:junit4]   2> 1531 T2709 oass.IndexSchema.readSchema default
>>> search field in schema is text
>>>> [junit4:junit4]   2> 1534 T2709 oass.IndexSchema.readSchema unique key
>>> field: id
>>>> [junit4:junit4]   2> 1545 T2709 oass.FileExchangeRateProvider.reload
>>> Reloading exchange rates from file currency.xml
>>>> [junit4:junit4]   2> 1549 T2709 oass.FileExchangeRateProvider.reload
>>> Reloading exchange rates from file currency.xml
>>>> [junit4:junit4]   2> 1552 T2709
>> oass.OpenExchangeRatesOrgProvider.reload
>>> Reloading exchange rates from open-exchange-rates.json
>>>> [junit4:junit4]   2> 1553 T2709
>> oass.OpenExchangeRatesOrgProvider.reload
>>> Reloading exchange rates from open-exchange-rates.json
>>>> [junit4:junit4]   2> 1554 T2709 oasc.SolrCore.<init> [collection1] Opening
>>> new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-
>> Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-
>>> 1357312117969/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/control/data/
>>>> [junit4:junit4]   2> 1555 T2709 oasc.JmxMonitoredMap.<init> JMX
>>> monitoring is enabled. Adding Solr mbeans to JMX Server:
>>> com.sun.jmx.mbeanserver.JmxMBeanServer@2089208e
>>>> [junit4:junit4]   2> 1555 T2709 oasc.SolrCore.initDirectoryFactory
>>> solr.StandardDirectoryFactory
>>>> [junit4:junit4]   2> 1556 T2709 oasc.CachingDirectoryFactory.get return
>> new
>>> directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/control/data forceNew:false
>>>> [junit4:junit4]   2> 1556 T2709 oasc.CachingDirectoryFactory.close
>> Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/control/data
>>>> [junit4:junit4]   2> 1557 T2709 oasc.SolrCore.getNewIndexDir New index
>>> directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/control/data/index/
>>>> [junit4:junit4]   2> 1557 T2709 oasc.SolrCore.initIndex WARNING
>>> [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/control/data/index' doesn't exist. Creating new index...
>>>> [junit4:junit4]   2> 1558 T2709 oasc.CachingDirectoryFactory.get return
>> new
>>> directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/control/data/index forceNew:false
>>>> [junit4:junit4]   2> 1589 T2709 oasc.SolrDeletionPolicy.onCommit
>>> SolrDeletionPolicy.onCommit: commits:num=1
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/control/data/index
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@59f504e6),segF
>>> N=segments_1,generation=1,filenames=[segments_1]
>>>> [junit4:junit4]   2> 1589 T2709 oasc.SolrDeletionPolicy.updateCommits
>>> newest commit = 1[segments_1]
>>>> [junit4:junit4]   2> 1590 T2709 oasc.CachingDirectoryFactory.close
>> Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/control/data/index
>>>> [junit4:junit4]   2> 1590 T2709 oasc.SolrCore.initWriters created xml:
>>> solr.XMLResponseWriter
>>>> [junit4:junit4]   2> 1592 T2709 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "dedupe"
>>>> [junit4:junit4]   2> 1592 T2709 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "dedupe-allfields"
>>>> [junit4:junit4]   2> 1592 T2709 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "stored_sig"
>>>> [junit4:junit4]   2> 1592 T2709 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "uniq-fields"
>>>> [junit4:junit4]   2> 1593 T2709 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "distrib-dup-test-chain-implicit"
>>>> [junit4:junit4]   2> 1593 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler:
>>> solr.ReplicationHandler
>>>> [junit4:junit4]   2> 1593 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created /replication:
>>> solr.ReplicationHandler
>>>> [junit4:junit4]   2> 1594 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created standard:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 1594 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created /get:
>>> solr.RealTimeGetHandler
>>>> [junit4:junit4]   2> 1594 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created dismax:
>>> solr.SearchHandler
>>>> [junit4:junit4]   2> 1595 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created mock:
>>> org.apache.solr.core.MockQuerySenderListenerReqHandler
>>>> [junit4:junit4]   2> 1595 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created /admin/:
>>> org.apache.solr.handler.admin.AdminHandlers
>>>> [junit4:junit4]   2> 1595 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created defaults:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 1595 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 1596 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created lazy:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 1596 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created /update:
>>> solr.UpdateRequestHandler
>>>> [junit4:junit4]   2> 1596 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created /terms:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 1597 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 1597 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created
>>> spellCheckCompRH_Direct:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 1597 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created
>>> spellCheckWithWordbreak:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 1598 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created
>>> spellCheckWithWordbreak_Direct:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 1598 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created
>> spellCheckCompRH1:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 1598 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created mltrh:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 1599 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created tvrh:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 1599 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created /mlt:
>>> solr.MoreLikeThisHandler
>>>> [junit4:junit4]   2> 1599 T2709
>>> oasc.RequestHandlers.initHandlersFromConfig created /debug/dump:
>>> solr.DumpRequestHandler
>>>> [junit4:junit4]   2> 1608 T2709 oashl.XMLLoader.init
>>> xsltCacheLifetimeSeconds=60
>>>> [junit4:junit4]   2> 1611 T2709 oasc.SolrCore.initDeprecatedSupport
>>> WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please
>>> update your config to use the ShowFileRequestHandler.
>>>> [junit4:junit4]   2> 1612 T2709 oasc.SolrCore.initDeprecatedSupport
>>> WARNING adding ShowFileRequestHandler with hidden files:
>> [SCHEMA.XML,
>>> OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-
>>> EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-
>>> ISOLATIN1ACCENT.TXT]
>>>> [junit4:junit4]   2> 1614 T2709 oasc.CachingDirectoryFactory.close
>> Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/control/data
>>>> [junit4:junit4]   2> 1615 T2709 oass.SolrIndexSearcher.<init> Opening
>>> Searcher@4024ce9b main
>>>> [junit4:junit4]   2> 1616 T2709 oasu.CommitTracker.<init> Hard
>>> AutoCommit: disabled
>>>> [junit4:junit4]   2> 1616 T2709 oasu.CommitTracker.<init> Soft
>> AutoCommit:
>>> disabled
>>>> [junit4:junit4]   2> 1616 T2709 oashc.SpellCheckComponent.inform
>>> Initializing spell checkers
>>>> [junit4:junit4]   2> 1632 T2709 oass.DirectSolrSpellChecker.init init:
>>> 
>> {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLe
>>> ngth=3}
>>>> [junit4:junit4]   2> 1679 T2710 oasc.SolrCore.registerSearcher [collection1]
>>> Registered new searcher Searcher@4024ce9b
>>> main{StandardDirectoryReader(segments_1:1)}
>>>> [junit4:junit4]   2> 1682 T2709 oasc.ZkController.publish publishing
>>> core=collection1 state=down
>>>> [junit4:junit4]   2> 1682 T2709 oasc.ZkController.publish numShards not
>>> found on descriptor - reading it from system property
>>>> [junit4:junit4]   2> 1683 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60003
>>> type:create cxid:0x50 zxid:0x29 txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for
>>> /solr/overseer/queue
>>>> [junit4:junit4]   2> 2392 T2707 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 2393 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Update state
>>> numShards=1 message={
>>>> [junit4:junit4]   2>      "operation":"state",
>>>> [junit4:junit4]   2>      "numShards":"1",
>>>> [junit4:junit4]   2>      "shard":null,
>>>> [junit4:junit4]   2>      "roles":null,
>>>> [junit4:junit4]   2>      "state":"down",
>>>> [junit4:junit4]   2>      "core":"collection1",
>>>> [junit4:junit4]   2>      "collection":"control_collection",
>>>> [junit4:junit4]   2>      "node_name":"127.0.0.1:25950_jxf%2Fdb",
>>>> [junit4:junit4]   2>      "base_url":"http://127.0.0.1:25950/jxf/db"}
>>>> [junit4:junit4]   2> 2393 T2707
>>> oasc.Overseer$ClusterStateUpdater.createCollection Create collection
>>> control_collection with numShards 1
>>>> [junit4:junit4]   2> 2394 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to
>>> shard shard=shard1
>>>> [junit4:junit4]   2> 2394 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60003
>>> type:create cxid:0x58 zxid:0x2c txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for
>>> /solr/overseer/queue-work
>>>> [junit4:junit4]   2> 2437 T2706 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> 2695 T2709 oasc.CoreContainer.registerCore registering
>>> core: collection1
>>>> [junit4:junit4]   2> 2695 T2709 oasc.ZkController.register Register replica -
>>> core:collection1 address:http://127.0.0.1:25950/jxf/db
>>> collection:control_collection shard:shard1
>>>> [junit4:junit4]   2> 2696 T2709 oascc.SolrZkClient.makePath makePath:
>>> /collections/control_collection/leader_elect/shard1/election
>>>> [junit4:junit4]   2> 2716 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60003
>>> type:delete cxid:0x72 zxid:0x36 txntype:-1 reqpath:n/a Error
>>> Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode =
>>> NoNode for /solr/collections/control_collection/leaders
>>>> [junit4:junit4]   2> 2717 T2709
>>> oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader
>>> process.
>>>> [junit4:junit4]   2> 2718 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60003
>>> type:create cxid:0x73 zxid:0x37 txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer Error:KeeperErrorCode = NodeExists for
>> /solr/overseer
>>>> [junit4:junit4]   2> 2726 T2709
>>> oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough
>>> replicas found to continue.
>>>> [junit4:junit4]   2> 2726 T2709
>>> oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new
>> leader
>>> - try and sync
>>>> [junit4:junit4]   2> 2726 T2709 oasc.SyncStrategy.sync Sync replicas to
>>> http://127.0.0.1:25950/jxf/db/collection1/
>>>> [junit4:junit4]   2> 2727 T2709 oasc.SyncStrategy.syncReplicas Sync
>> Success -
>>> now sync replicas to me
>>>> [junit4:junit4]   2> 2727 T2709 oasc.SyncStrategy.syncToMe
>>> http://127.0.0.1:25950/jxf/db/collection1/ has no replicas
>>>> [junit4:junit4]   2> 2727 T2709
>>> oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader:
>>> http://127.0.0.1:25950/jxf/db/collection1/
>>>> [junit4:junit4]   2> 2727 T2709 oascc.SolrZkClient.makePath makePath:
>>> /collections/control_collection/leaders/shard1
>>>> [junit4:junit4]   2> 2732 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60003
>>> type:create cxid:0x7d zxid:0x3b txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer Error:KeeperErrorCode = NodeExists for
>> /solr/overseer
>>>> [junit4:junit4]   2> 3942 T2707 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 3993 T2706 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> 4015 T2709 oasc.ZkController.register We are
>>> http://127.0.0.1:25950/jxf/db/collection1/ and leader is
>>> http://127.0.0.1:25950/jxf/db/collection1/
>>>> [junit4:junit4]   2> 4015 T2709 oasc.ZkController.register No LogReplay
>>> needed for core=collection1 baseURL=http://127.0.0.1:25950/jxf/db
>>>> [junit4:junit4]   2> 4015 T2709 oasc.ZkController.checkRecovery I am the
>>> leader, no recovery necessary
>>>> [junit4:junit4]   2> 4015 T2709 oasc.ZkController.publish publishing
>>> core=collection1 state=active
>>>> [junit4:junit4]   2> 4015 T2709 oasc.ZkController.publish numShards not
>>> found on descriptor - reading it from system property
>>>> [junit4:junit4]   2> 4017 T2709 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 4018 T2684 oass.SolrDispatchFilter.init
>>> user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1
>>>> [junit4:junit4]   2> 4018 T2684 oass.SolrDispatchFilter.init
>>> SolrDispatchFilter.init() done
>>>> [junit4:junit4]   2> 4019 T2684 oascsi.HttpClientUtil.createClient Creating
>>> new http client,
>>> 
>> config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=
>>> false
>>>> [junit4:junit4]   2> 4033 T2684 oascsi.HttpClientUtil.createClient Creating
>>> new http client, config:
>>>> [junit4:junit4]   2> 4041 T2684 oaz.ZooKeeper.<init> Initiating client
>>> connection, connectString=127.0.0.1:24224/solr sessionTimeout=10000
>>> watcher=org.apache.solr.common.cloud.ConnectionManager@191d098d
>>>> [junit4:junit4]   2> 4042 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Waiting for client to connect to ZooKeeper
>>>> [junit4:junit4]   2> 4043 T2711
>> oaz.ClientCnxn$SendThread.logStartConnect
>>> Opening socket connection to server localhost/127.0.0.1:24224. Will not
>>> attempt to authenticate using SASL (access denied
>>> ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
>>>> [junit4:junit4]   2> 4043 T2711
>>> oaz.ClientCnxn$SendThread.primeConnection Socket connection
>> established
>>> to localhost/127.0.0.1:24224, initiating session
>>>> [junit4:junit4]   2> 4043 T2686 oazs.NIOServerCnxnFactory.run Accepted
>>> socket connection from /140.211.11.196:36384
>>>> [junit4:junit4]   2> 4044 T2686
>>> oazs.ZooKeeperServer.processConnectRequest Client attempting to
>>> establish new session at /140.211.11.196:36384
>>>> [junit4:junit4]   2> 4045 T2688 oazs.ZooKeeperServer.finishSessionInit
>>> Established session 0x13c061b4ba60004 with negotiated timeout 10000 for
>>> client /140.211.11.196:36384
>>>> [junit4:junit4]   2> 4045 T2711 oaz.ClientCnxn$SendThread.onConnected
>>> Session establishment complete on server localhost/127.0.0.1:24224,
>>> sessionid = 0x13c061b4ba60004, negotiated timeout = 10000
>>>> [junit4:junit4]   2> 4045 T2712 oascc.ConnectionManager.process Watcher
>>> org.apache.solr.common.cloud.ConnectionManager@191d098d
>>> name:ZooKeeperConnection Watcher:127.0.0.1:24224/solr got event
>>> WatchedEvent state:SyncConnected type:None path:null path:null
>>> type:None
>>>> [junit4:junit4]   2> 4046 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Client is connected to ZooKeeper
>>>> [junit4:junit4]   2> 4046 T2684
>>> oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating
>>> cluster state from ZooKeeper...
>>>> [junit4:junit4]   2> 4048 T2684 oasc.ChaosMonkey.monkeyLog monkey:
>> init
>>> - expire sessions:true cause connection loss:true
>>>> [junit4:junit4]   2> 4215 T2684 oejs.Server.doStart jetty-8.1.8.v20121106
>>>> [junit4:junit4]   2> 4219 T2684 oejs.AbstractConnector.doStart Started
>>> SocketConnector@127.0.0.1:32591
>>>> [junit4:junit4]   2> 4219 T2684 oasc.SolrResourceLoader.locateSolrHome
>>> JNDI not configured for solr (NoInitialContextEx)
>>>> [junit4:junit4]   2> 4220 T2684 oasc.SolrResourceLoader.locateSolrHome
>>> using system property solr.solr.home: /usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1357312121708
>>>> [junit4:junit4]   2> 4221 T2684 oasc.SolrResourceLoader.<init> new
>>> SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1357312121708/'
>>>> [junit4:junit4]   2> 4266 T2684 oass.SolrDispatchFilter.init
>>> SolrDispatchFilter.init()
>>>> [junit4:junit4]   2> 4266 T2684 oasc.SolrResourceLoader.locateSolrHome
>>> JNDI not configured for solr (NoInitialContextEx)
>>>> [junit4:junit4]   2> 4267 T2684 oasc.SolrResourceLoader.locateSolrHome
>>> using system property solr.solr.home: /usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1357312121708
>>>> [junit4:junit4]   2> 4267 T2684 oasc.CoreContainer$Initializer.initialize
>>> looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-
>>> Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-
>>> 1357312121708/solr.xml
>>>> [junit4:junit4]   2> 4268 T2684 oasc.CoreContainer.<init> New
>>> CoreContainer 578925509
>>>> [junit4:junit4]   2> 4269 T2684 oasc.CoreContainer.load Loading
>>> CoreContainer using Solr Home: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1357312121708/'
>>> 
>>>> [junit4:junit4]   2> 4270 T2684 oasc.SolrResourceLoader.<init> new
>>> SolrResourceLoader for directory: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1357312121708/'
>>>> [junit4:junit4]   2> 4301 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to:
>>> 30000
>>>> [junit4:junit4]   2> 4302 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
>> http://
>>>> [junit4:junit4]   2> 4302 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to:
>>> 15000
>>>> [junit4:junit4]   2> 4303 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting
>>> maxConnectionsPerHost to: 20
>>>> [junit4:junit4]   2> 4303 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
>>>> [junit4:junit4]   2> 4304 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize
>> to:
>>> 2147483647
>>>> [junit4:junit4]   2> 4304 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime
>>> to: 5
>>>> [junit4:junit4]   2> 4305 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
>>>> [junit4:junit4]   2> 4306 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to:
>> false
>>>> [junit4:junit4]   2> 4306 T2684 oascsi.HttpClientUtil.createClient Creating
>>> new http client,
>>> 
>> config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout
>>> =30000&connTimeout=15000&retry=false
>>>> [junit4:junit4]   2> 4326 T2684 oasc.CoreContainer.load Registering Log
>>> Listener
>>>> [junit4:junit4]   2> 4346 T2684 oasc.CoreContainer.initZooKeeper
>>> Zookeeper client=127.0.0.1:24224/solr
>>>> [junit4:junit4]   2> 4347 T2684 oasc.ZkController.checkChrootPath zkHost
>>> includes chroot
>>>> [junit4:junit4]   2> 4347 T2684 oaz.ZooKeeper.<init> Initiating client
>>> connection, connectString=127.0.0.1:24224 sessionTimeout=60000
>>> watcher=org.apache.solr.common.cloud.ConnectionManager@2f71f5f9
>>>> [junit4:junit4]   2> 4348 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Waiting for client to connect to ZooKeeper
>>>> [junit4:junit4]   2> 4349 T2722
>> oaz.ClientCnxn$SendThread.logStartConnect
>>> Opening socket connection to server localhost/127.0.0.1:24224. Will not
>>> attempt to authenticate using SASL (access denied
>>> ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
>>>> [junit4:junit4]   2> 4349 T2722
>>> oaz.ClientCnxn$SendThread.primeConnection Socket connection
>> established
>>> to localhost/127.0.0.1:24224, initiating session
>>>> [junit4:junit4]   2> 4350 T2686 oazs.NIOServerCnxnFactory.run Accepted
>>> socket connection from /140.211.11.196:34324
>>>> [junit4:junit4]   2> 4350 T2686
>>> oazs.ZooKeeperServer.processConnectRequest Client attempting to
>>> establish new session at /140.211.11.196:34324
>>>> [junit4:junit4]   2> 4352 T2688 oazs.ZooKeeperServer.finishSessionInit
>>> Established session 0x13c061b4ba60005 with negotiated timeout 20000 for
>>> client /140.211.11.196:34324
>>>> [junit4:junit4]   2> 4352 T2722 oaz.ClientCnxn$SendThread.onConnected
>>> Session establishment complete on server localhost/127.0.0.1:24224,
>>> sessionid = 0x13c061b4ba60005, negotiated timeout = 20000
>>>> [junit4:junit4]   2> 4353 T2723 oascc.ConnectionManager.process Watcher
>>> org.apache.solr.common.cloud.ConnectionManager@2f71f5f9
>>> name:ZooKeeperConnection Watcher:127.0.0.1:24224 got event
>>> WatchedEvent state:SyncConnected type:None path:null path:null
>>> type:None
>>>> [junit4:junit4]   2> 4353 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Client is connected to ZooKeeper
>>>> [junit4:junit4]   2> 4354 T2689 oazs.PrepRequestProcessor.pRequest2Txn
>>> Processed session termination for sessionid: 0x13c061b4ba60005
>>>> [junit4:junit4]   2> 4367 T2723 oaz.ClientCnxn$EventThread.run
>>> EventThread shut down
>>>> [junit4:junit4]   2> 4367 T2686 oazs.NIOServerCnxn.closeSock Closed
>> socket
>>> connection for client /140.211.11.196:34324 which had sessionid
>>> 0x13c061b4ba60005
>>>> [junit4:junit4]   2> 4367 T2684 oaz.ZooKeeper.close Session:
>>> 0x13c061b4ba60005 closed
>>>> [junit4:junit4]   2> 4368 T2684 oascsi.HttpClientUtil.createClient Creating
>>> new http client,
>>> 
>> config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=
>>> 15000&connTimeout=30000
>>>> [junit4:junit4]   2> 4377 T2684 oaz.ZooKeeper.<init> Initiating client
>>> connection, connectString=127.0.0.1:24224/solr sessionTimeout=30000
>>> watcher=org.apache.solr.common.cloud.ConnectionManager@bfb9e2e
>>>> [junit4:junit4]   2> 4378 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Waiting for client to connect to ZooKeeper
>>>> [junit4:junit4]   2> 4379 T2724
>> oaz.ClientCnxn$SendThread.logStartConnect
>>> Opening socket connection to server localhost/127.0.0.1:24224. Will not
>>> attempt to authenticate using SASL (access denied
>>> ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
>>>> [junit4:junit4]   2> 4379 T2724
>>> oaz.ClientCnxn$SendThread.primeConnection Socket connection
>> established
>>> to localhost/127.0.0.1:24224, initiating session
>>>> [junit4:junit4]   2> 4379 T2686 oazs.NIOServerCnxnFactory.run Accepted
>>> socket connection from /140.211.11.196:39200
>>>> [junit4:junit4]   2> 4380 T2686
>>> oazs.ZooKeeperServer.processConnectRequest Client attempting to
>>> establish new session at /140.211.11.196:39200
>>>> [junit4:junit4]   2> 4381 T2688 oazs.ZooKeeperServer.finishSessionInit
>>> Established session 0x13c061b4ba60006 with negotiated timeout 20000 for
>>> client /140.211.11.196:39200
>>>> [junit4:junit4]   2> 4381 T2724 oaz.ClientCnxn$SendThread.onConnected
>>> Session establishment complete on server localhost/127.0.0.1:24224,
>>> sessionid = 0x13c061b4ba60006, negotiated timeout = 20000
>>>> [junit4:junit4]   2> 4381 T2725 oascc.ConnectionManager.process Watcher
>>> org.apache.solr.common.cloud.ConnectionManager@bfb9e2e
>>> name:ZooKeeperConnection Watcher:127.0.0.1:24224/solr got event
>>> WatchedEvent state:SyncConnected type:None path:null path:null
>>> type:None
>>>> [junit4:junit4]   2> 4382 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Client is connected to ZooKeeper
>>>> [junit4:junit4]   2> 4382 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60006
>>> type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer Error:KeeperErrorCode = NodeExists for
>> /solr/overseer
>>>> [junit4:junit4]   2> 4384 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60006
>>> type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer Error:KeeperErrorCode = NodeExists for
>> /solr/overseer
>>>> [junit4:junit4]   2> 4392 T2684
>> oasc.ZkController.createEphemeralLiveNode
>>> Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32591_jxf%2Fdb
>>>> [junit4:junit4]   2> 4393 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60006
>>> type:delete cxid:0x4 zxid:0x4b txntype:-1 reqpath:n/a Error
>>> Path:/solr/live_nodes/127.0.0.1:32591_jxf%2Fdb Error:KeeperErrorCode =
>>> NoNode for /solr/live_nodes/127.0.0.1:32591_jxf%2Fdb
>>>> [junit4:junit4]   2> 4394 T2684 oascc.SolrZkClient.makePath makePath:
>>> /live_nodes/127.0.0.1:32591_jxf%2Fdb
>>>> [junit4:junit4]   2> 4397 T2706 oascc.ZkStateReader$3.process Updating
>> live
>>> nodes... (2)
>>>> [junit4:junit4]   2> 4398 T2712 oascc.ZkStateReader$3.process Updating
>> live
>>> nodes... (2)
>>>> [junit4:junit4]   2> 4398 T2706 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> 4406 T2684
>>> oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating
>>> cluster state from ZooKeeper...
>>>> [junit4:junit4]   2> 4413 T2726 oasc.CoreContainer.create Creating
>> SolrCore
>>> 'collection1' using instanceDir: /usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-
>>> 1357312121708/collection1
>>>> [junit4:junit4]   2> 4413 T2726 oasc.ZkController.createCollectionZkNode
>>> Check for collection zkNode:collection1
>>>> [junit4:junit4]   2> 4414 T2726 oasc.ZkController.createCollectionZkNode
>>> Collection zkNode exists
>>>> [junit4:junit4]   2> 4414 T2726 oasc.ZkController.readConfigName Load
>>> collection config from:/collections/collection1
>>>> [junit4:junit4]   2> 4415 T2726 oasc.SolrResourceLoader.<init> new
>>> SolrResourceLoader for directory: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-
>>> 1357312121708/collection1/'
>>>> [junit4:junit4]   2> 4416 T2726
>> oasc.SolrResourceLoader.replaceClassLoader
>>> Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty1-
>>> 1357312121708/collection1/lib/classes/' to classloader
>>>> [junit4:junit4]   2> 4417 T2726
>> oasc.SolrResourceLoader.replaceClassLoader
>>> Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty1-
>>> 1357312121708/collection1/lib/README' to classloader
>>>> [junit4:junit4]   2> 4474 T2726 oasc.SolrConfig.<init> Using Lucene
>>> MatchVersion: LUCENE_41
>>>> [junit4:junit4]   2> 4522 T2726 oasc.SolrConfig.<init> Loaded SolrConfig:
>>> solrconfig.xml
>>>> [junit4:junit4]   2> 4623 T2726 oass.IndexSchema.readSchema Reading
>> Solr
>>> Schema
>>>> [junit4:junit4]   2> 4627 T2726 oass.IndexSchema.readSchema Schema
>>> name=test
>>>> [junit4:junit4]   2> 5042 T2726 oass.OpenExchangeRatesOrgProvider.init
>>> Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>>>> [junit4:junit4]   2> 5049 T2726 oass.IndexSchema.readSchema default
>>> search field in schema is text
>>>> [junit4:junit4]   2> 5052 T2726 oass.IndexSchema.readSchema unique key
>>> field: id
>>>> [junit4:junit4]   2> 5063 T2726 oass.FileExchangeRateProvider.reload
>>> Reloading exchange rates from file currency.xml
>>>> [junit4:junit4]   2> 5066 T2726 oass.FileExchangeRateProvider.reload
>>> Reloading exchange rates from file currency.xml
>>>> [junit4:junit4]   2> 5069 T2726
>> oass.OpenExchangeRatesOrgProvider.reload
>>> Reloading exchange rates from open-exchange-rates.json
>>>> [junit4:junit4]   2> 5070 T2726
>> oass.OpenExchangeRatesOrgProvider.reload
>>> Reloading exchange rates from open-exchange-rates.json
>>>> [junit4:junit4]   2> 5071 T2726 oasc.SolrCore.<init> [collection1] Opening
>>> new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-
>> Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-
>>> 1357312121708/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1/
>>>> [junit4:junit4]   2> 5071 T2726 oasc.JmxMonitoredMap.<init> JMX
>>> monitoring is enabled. Adding Solr mbeans to JMX Server:
>>> com.sun.jmx.mbeanserver.JmxMBeanServer@2089208e
>>>> [junit4:junit4]   2> 5072 T2726 oasc.SolrCore.initDirectoryFactory
>>> solr.StandardDirectoryFactory
>>>> [junit4:junit4]   2> 5072 T2726 oasc.CachingDirectoryFactory.get return
>> new
>>> directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1357312117664/jetty1
>>> forceNew:false
>>>> [junit4:junit4]   2> 5073 T2726 oasc.CachingDirectoryFactory.close
>> Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1
>>>> [junit4:junit4]   2> 5073 T2726 oasc.SolrCore.getNewIndexDir New index
>>> directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1/index/
>>>> [junit4:junit4]   2> 5074 T2726 oasc.SolrCore.initIndex WARNING
>>> [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1/index' doesn't exist. Creating new index...
>>>> [junit4:junit4]   2> 5074 T2726 oasc.CachingDirectoryFactory.get return
>> new
>>> directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1/index forceNew:false
>>>> [junit4:junit4]   2> 5078 T2726 oasc.SolrDeletionPolicy.onCommit
>>> SolrDeletionPolicy.onCommit: commits:num=1
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1/index
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@7556f92c),segFN
>>> =segments_1,generation=1,filenames=[segments_1]
>>>> [junit4:junit4]   2> 5079 T2726 oasc.SolrDeletionPolicy.updateCommits
>>> newest commit = 1[segments_1]
>>>> [junit4:junit4]   2> 5079 T2726 oasc.CachingDirectoryFactory.close
>> Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1/index
>>>> [junit4:junit4]   2> 5079 T2726 oasc.SolrCore.initWriters created xml:
>>> solr.XMLResponseWriter
>>>> [junit4:junit4]   2> 5081 T2726 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "dedupe"
>>>> [junit4:junit4]   2> 5081 T2726 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "dedupe-allfields"
>>>> [junit4:junit4]   2> 5082 T2726 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "stored_sig"
>>>> [junit4:junit4]   2> 5082 T2726 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "uniq-fields"
>>>> [junit4:junit4]   2> 5082 T2726 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "distrib-dup-test-chain-implicit"
>>>> [junit4:junit4]   2> 5082 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler:
>>> solr.ReplicationHandler
>>>> [junit4:junit4]   2> 5083 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created /replication:
>>> solr.ReplicationHandler
>>>> [junit4:junit4]   2> 5083 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created standard:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 5084 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created /get:
>>> solr.RealTimeGetHandler
>>>> [junit4:junit4]   2> 5084 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created dismax:
>>> solr.SearchHandler
>>>> [junit4:junit4]   2> 5085 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created mock:
>>> org.apache.solr.core.MockQuerySenderListenerReqHandler
>>>> [junit4:junit4]   2> 5085 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created /admin/:
>>> org.apache.solr.handler.admin.AdminHandlers
>>>> [junit4:junit4]   2> 5085 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created defaults:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 5085 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 5086 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created lazy:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 5086 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created /update:
>>> solr.UpdateRequestHandler
>>>> [junit4:junit4]   2> 5086 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created /terms:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 5087 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 5087 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created
>>> spellCheckCompRH_Direct:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 5088 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created
>>> spellCheckWithWordbreak:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 5088 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created
>>> spellCheckWithWordbreak_Direct:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 5089 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created
>> spellCheckCompRH1:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 5089 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created mltrh:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 5089 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created tvrh:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 5090 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created /mlt:
>>> solr.MoreLikeThisHandler
>>>> [junit4:junit4]   2> 5090 T2726
>>> oasc.RequestHandlers.initHandlersFromConfig created /debug/dump:
>>> solr.DumpRequestHandler
>>>> [junit4:junit4]   2> 5099 T2726 oashl.XMLLoader.init
>>> xsltCacheLifetimeSeconds=60
>>>> [junit4:junit4]   2> 5102 T2726 oasc.SolrCore.initDeprecatedSupport
>>> WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please
>>> update your config to use the ShowFileRequestHandler.
>>>> [junit4:junit4]   2> 5103 T2726 oasc.SolrCore.initDeprecatedSupport
>>> WARNING adding ShowFileRequestHandler with hidden files:
>> [SCHEMA.XML,
>>> OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-
>>> EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-
>>> ISOLATIN1ACCENT.TXT]
>>>> [junit4:junit4]   2> 5105 T2726 oasc.CachingDirectoryFactory.close
>> Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1
>>>> [junit4:junit4]   2> 5106 T2726 oass.SolrIndexSearcher.<init> Opening
>>> Searcher@c8fd94d main
>>>> [junit4:junit4]   2> 5107 T2726 oasu.CommitTracker.<init> Hard
>>> AutoCommit: disabled
>>>> [junit4:junit4]   2> 5107 T2726 oasu.CommitTracker.<init> Soft
>> AutoCommit:
>>> disabled
>>>> [junit4:junit4]   2> 5107 T2726 oashc.SpellCheckComponent.inform
>>> Initializing spell checkers
>>>> [junit4:junit4]   2> 5112 T2726 oass.DirectSolrSpellChecker.init init:
>>> 
>> {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLe
>>> ngth=3}
>>>> [junit4:junit4]   2> 5162 T2727 oasc.SolrCore.registerSearcher [collection1]
>>> Registered new searcher Searcher@c8fd94d
>>> main{StandardDirectoryReader(segments_1:1)}
>>>> [junit4:junit4]   2> 5165 T2726 oasc.ZkController.publish publishing
>>> core=collection1 state=down
>>>> [junit4:junit4]   2> 5165 T2726 oasc.ZkController.publish numShards not
>>> found on descriptor - reading it from system property
>>>> [junit4:junit4]   2> 5508 T2707 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 5508 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Update state
>>> numShards=1 message={
>>>> [junit4:junit4]   2>      "operation":"state",
>>>> [junit4:junit4]   2>      "numShards":"1",
>>>> [junit4:junit4]   2>      "shard":"shard1",
>>>> [junit4:junit4]   2>      "roles":null,
>>>> [junit4:junit4]   2>      "state":"active",
>>>> [junit4:junit4]   2>      "core":"collection1",
>>>> [junit4:junit4]   2>      "collection":"control_collection",
>>>> [junit4:junit4]   2>      "node_name":"127.0.0.1:25950_jxf%2Fdb",
>>>> [junit4:junit4]   2>      "base_url":"http://127.0.0.1:25950/jxf/db"}
>>>> [junit4:junit4]   2> 5541 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Update state
>>> numShards=1 message={
>>>> [junit4:junit4]   2>      "operation":"state",
>>>> [junit4:junit4]   2>      "numShards":"1",
>>>> [junit4:junit4]   2>      "shard":null,
>>>> [junit4:junit4]   2>      "roles":null,
>>>> [junit4:junit4]   2>      "state":"down",
>>>> [junit4:junit4]   2>      "core":"collection1",
>>>> [junit4:junit4]   2>      "collection":"collection1",
>>>> [junit4:junit4]   2>      "node_name":"127.0.0.1:32591_jxf%2Fdb",
>>>> [junit4:junit4]   2>      "base_url":"http://127.0.0.1:32591/jxf/db"}
>>>> [junit4:junit4]   2> 5542 T2707
>>> oasc.Overseer$ClusterStateUpdater.createCollection Create collection
>>> collection1 with numShards 1
>>>> [junit4:junit4]   2> 5542 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to
>>> shard shard=shard1
>>>> [junit4:junit4]   2> 5566 T2706 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> 5566 T2725 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> 5566 T2712 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> 6168 T2726 oasc.CoreContainer.registerCore registering
>>> core: collection1
>>>> [junit4:junit4]   2> 6168 T2726 oasc.ZkController.register Register replica -
>>> core:collection1 address:http://127.0.0.1:32591/jxf/db
>> collection:collection1
>>> shard:shard1
>>>> [junit4:junit4]   2> 6169 T2726 oascc.SolrZkClient.makePath makePath:
>>> /collections/collection1/leader_elect/shard1/election
>>>> [junit4:junit4]   2> 6196 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60006
>>> type:delete cxid:0x43 zxid:0x5a txntype:-1 reqpath:n/a Error
>>> Path:/solr/collections/collection1/leaders Error:KeeperErrorCode =
>> NoNode
>>> for /solr/collections/collection1/leaders
>>>> [junit4:junit4]   2> 6197 T2726
>>> oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader
>>> process.
>>>> [junit4:junit4]   2> 6198 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60006
>>> type:create cxid:0x44 zxid:0x5b txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer Error:KeeperErrorCode = NodeExists for
>> /solr/overseer
>>>> [junit4:junit4]   2> 6208 T2726
>>> oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough
>>> replicas found to continue.
>>>> [junit4:junit4]   2> 6208 T2726
>>> oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new
>> leader
>>> - try and sync
>>>> [junit4:junit4]   2> 6209 T2726 oasc.SyncStrategy.sync Sync replicas to
>>> http://127.0.0.1:32591/jxf/db/collection1/
>>>> [junit4:junit4]   2> 6209 T2726 oasc.SyncStrategy.syncReplicas Sync
>> Success -
>>> now sync replicas to me
>>>> [junit4:junit4]   2> 6209 T2726 oasc.SyncStrategy.syncToMe
>>> http://127.0.0.1:32591/jxf/db/collection1/ has no replicas
>>>> [junit4:junit4]   2> 6209 T2726
>>> oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader:
>>> http://127.0.0.1:32591/jxf/db/collection1/
>>>> [junit4:junit4]   2> 6210 T2726 oascc.SolrZkClient.makePath makePath:
>>> /collections/collection1/leaders/shard1
>>>> [junit4:junit4]   2> 6214 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60006
>>> type:create cxid:0x4e zxid:0x5f txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer Error:KeeperErrorCode = NodeExists for
>> /solr/overseer
>>>> [junit4:junit4]   2> 7107 T2707 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 7150 T2706 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> 7150 T2725 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> 7150 T2712 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> 7193 T2726 oasc.ZkController.register We are
>>> http://127.0.0.1:32591/jxf/db/collection1/ and leader is
>>> http://127.0.0.1:32591/jxf/db/collection1/
>>>> [junit4:junit4]   2> 7193 T2726 oasc.ZkController.register No LogReplay
>>> needed for core=collection1 baseURL=http://127.0.0.1:32591/jxf/db
>>>> [junit4:junit4]   2> 7193 T2726 oasc.ZkController.checkRecovery I am the
>>> leader, no recovery necessary
>>>> [junit4:junit4]   2> 7193 T2726 oasc.ZkController.publish publishing
>>> core=collection1 state=active
>>>> [junit4:junit4]   2> 7193 T2726 oasc.ZkController.publish numShards not
>>> found on descriptor - reading it from system property
>>>> [junit4:junit4]   2> 7195 T2726 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 7196 T2684 oass.SolrDispatchFilter.init
>>> user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1
>>>> [junit4:junit4]   2> 7197 T2684 oass.SolrDispatchFilter.init
>>> SolrDispatchFilter.init() done
>>>> [junit4:junit4]   2> 7197 T2684 oascsi.HttpClientUtil.createClient Creating
>>> new http client,
>>> 
>> config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=
>>> false
>>>> [junit4:junit4]   2> 7376 T2684 oejs.Server.doStart jetty-8.1.8.v20121106
>>>> [junit4:junit4]   2> 7379 T2684 oejs.AbstractConnector.doStart Started
>>> SocketConnector@127.0.0.1:38364
>>>> [junit4:junit4]   2> 7380 T2684 oasc.SolrResourceLoader.locateSolrHome
>>> JNDI not configured for solr (NoInitialContextEx)
>>>> [junit4:junit4]   2> 7381 T2684 oasc.SolrResourceLoader.locateSolrHome
>>> using system property solr.solr.home: /usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1357312124870
>>>> [junit4:junit4]   2> 7382 T2684 oasc.SolrResourceLoader.<init> new
>>> SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1357312124870/'
>>>> [junit4:junit4]   2> 7426 T2684 oass.SolrDispatchFilter.init
>>> SolrDispatchFilter.init()
>>>> [junit4:junit4]   2> 7426 T2684 oasc.SolrResourceLoader.locateSolrHome
>>> JNDI not configured for solr (NoInitialContextEx)
>>>> [junit4:junit4]   2> 7427 T2684 oasc.SolrResourceLoader.locateSolrHome
>>> using system property solr.solr.home: /usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1357312124870
>>>> [junit4:junit4]   2> 7428 T2684 oasc.CoreContainer$Initializer.initialize
>>> looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-
>>> Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-
>>> 1357312124870/solr.xml
>>>> [junit4:junit4]   2> 7428 T2684 oasc.CoreContainer.<init> New
>>> CoreContainer 826782344
>>>> [junit4:junit4]   2> 7429 T2684 oasc.CoreContainer.load Loading
>>> CoreContainer using Solr Home: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1357312124870/'
>>> 
>>>> [junit4:junit4]   2> 7429 T2684 oasc.SolrResourceLoader.<init> new
>>> SolrResourceLoader for directory: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1357312124870/'
>>>> [junit4:junit4]   2> 7461 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to:
>>> 30000
>>>> [junit4:junit4]   2> 7461 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
>> http://
>>>> [junit4:junit4]   2> 7462 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to:
>>> 15000
>>>> [junit4:junit4]   2> 7462 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting
>>> maxConnectionsPerHost to: 20
>>>> [junit4:junit4]   2> 7463 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
>>>> [junit4:junit4]   2> 7463 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize
>> to:
>>> 2147483647
>>>> [junit4:junit4]   2> 7464 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime
>>> to: 5
>>>> [junit4:junit4]   2> 7464 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
>>>> [junit4:junit4]   2> 7465 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to:
>> false
>>>> [junit4:junit4]   2> 7465 T2684 oascsi.HttpClientUtil.createClient Creating
>>> new http client,
>>> 
>> config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout
>>> =30000&connTimeout=15000&retry=false
>>>> [junit4:junit4]   2> 7486 T2684 oasc.CoreContainer.load Registering Log
>>> Listener
>>>> [junit4:junit4]   2> 7506 T2684 oasc.CoreContainer.initZooKeeper
>>> Zookeeper client=127.0.0.1:24224/solr
>>>> [junit4:junit4]   2> 7507 T2684 oasc.ZkController.checkChrootPath zkHost
>>> includes chroot
>>>> [junit4:junit4]   2> 7507 T2684 oaz.ZooKeeper.<init> Initiating client
>>> connection, connectString=127.0.0.1:24224 sessionTimeout=60000
>>> watcher=org.apache.solr.common.cloud.ConnectionManager@3858813c
>>>> [junit4:junit4]   2> 7508 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Waiting for client to connect to ZooKeeper
>>>> [junit4:junit4]   2> 7509 T2737
>> oaz.ClientCnxn$SendThread.logStartConnect
>>> Opening socket connection to server localhost/127.0.0.1:24224. Will not
>>> attempt to authenticate using SASL (access denied
>>> ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
>>>> [junit4:junit4]   2> 7509 T2737
>>> oaz.ClientCnxn$SendThread.primeConnection Socket connection
>> established
>>> to localhost/127.0.0.1:24224, initiating session
>>>> [junit4:junit4]   2> 7510 T2686 oazs.NIOServerCnxnFactory.run Accepted
>>> socket connection from /140.211.11.196:23764
>>>> [junit4:junit4]   2> 7510 T2686
>>> oazs.ZooKeeperServer.processConnectRequest Client attempting to
>>> establish new session at /140.211.11.196:23764
>>>> [junit4:junit4]   2> 7512 T2688 oazs.ZooKeeperServer.finishSessionInit
>>> Established session 0x13c061b4ba60007 with negotiated timeout 20000 for
>>> client /140.211.11.196:23764
>>>> [junit4:junit4]   2> 7512 T2737 oaz.ClientCnxn$SendThread.onConnected
>>> Session establishment complete on server localhost/127.0.0.1:24224,
>>> sessionid = 0x13c061b4ba60007, negotiated timeout = 20000
>>>> [junit4:junit4]   2> 7512 T2738 oascc.ConnectionManager.process Watcher
>>> org.apache.solr.common.cloud.ConnectionManager@3858813c
>>> name:ZooKeeperConnection Watcher:127.0.0.1:24224 got event
>>> WatchedEvent state:SyncConnected type:None path:null path:null
>>> type:None
>>>> [junit4:junit4]   2> 7513 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Client is connected to ZooKeeper
>>>> [junit4:junit4]   2> 7514 T2689 oazs.PrepRequestProcessor.pRequest2Txn
>>> Processed session termination for sessionid: 0x13c061b4ba60007
>>>> [junit4:junit4]   2> 7515 T2738 oaz.ClientCnxn$EventThread.run
>>> EventThread shut down
>>>> [junit4:junit4]   2> 7515 T2686 oazs.NIOServerCnxn.closeSock Closed
>> socket
>>> connection for client /140.211.11.196:23764 which had sessionid
>>> 0x13c061b4ba60007
>>>> [junit4:junit4]   2> 7515 T2684 oaz.ZooKeeper.close Session:
>>> 0x13c061b4ba60007 closed
>>>> [junit4:junit4]   2> 7515 T2684 oascsi.HttpClientUtil.createClient Creating
>>> new http client,
>>> 
>> config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=
>>> 15000&connTimeout=30000
>>>> [junit4:junit4]   2> 7527 T2684 oaz.ZooKeeper.<init> Initiating client
>>> connection, connectString=127.0.0.1:24224/solr sessionTimeout=30000
>>> watcher=org.apache.solr.common.cloud.ConnectionManager@37be4a7c
>>>> [junit4:junit4]   2> 7528 T2739
>> oaz.ClientCnxn$SendThread.logStartConnect
>>> Opening socket connection to server localhost/127.0.0.1:24224. Will not
>>> attempt to authenticate using SASL (access denied
>>> ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
>>>> [junit4:junit4]   2> 7528 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Waiting for client to connect to ZooKeeper
>>>> [junit4:junit4]   2> 7528 T2739
>>> oaz.ClientCnxn$SendThread.primeConnection Socket connection
>> established
>>> to localhost/127.0.0.1:24224, initiating session
>>>> [junit4:junit4]   2> 7529 T2686 oazs.NIOServerCnxnFactory.run Accepted
>>> socket connection from /140.211.11.196:42953
>>>> [junit4:junit4]   2> 7529 T2686
>>> oazs.ZooKeeperServer.processConnectRequest Client attempting to
>>> establish new session at /140.211.11.196:42953
>>>> [junit4:junit4]   2> 7530 T2688 oazs.ZooKeeperServer.finishSessionInit
>>> Established session 0x13c061b4ba60008 with negotiated timeout 20000 for
>>> client /140.211.11.196:42953
>>>> [junit4:junit4]   2> 7530 T2739 oaz.ClientCnxn$SendThread.onConnected
>>> Session establishment complete on server localhost/127.0.0.1:24224,
>>> sessionid = 0x13c061b4ba60008, negotiated timeout = 20000
>>>> [junit4:junit4]   2> 7531 T2740 oascc.ConnectionManager.process Watcher
>>> org.apache.solr.common.cloud.ConnectionManager@37be4a7c
>>> name:ZooKeeperConnection Watcher:127.0.0.1:24224/solr got event
>>> WatchedEvent state:SyncConnected type:None path:null path:null
>>> type:None
>>>> [junit4:junit4]   2> 7531 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Client is connected to ZooKeeper
>>>> [junit4:junit4]   2> 7532 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60008
>>> type:create cxid:0x1 zxid:0x6c txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer Error:KeeperErrorCode = NodeExists for
>> /solr/overseer
>>>> [junit4:junit4]   2> 7533 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60008
>>> type:create cxid:0x2 zxid:0x6d txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer Error:KeeperErrorCode = NodeExists for
>> /solr/overseer
>>>> [junit4:junit4]   2> 7534 T2684
>> oasc.ZkController.createEphemeralLiveNode
>>> Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38364_jxf%2Fdb
>>>> [junit4:junit4]   2> 7535 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba60008
>>> type:delete cxid:0x4 zxid:0x6e txntype:-1 reqpath:n/a Error
>>> Path:/solr/live_nodes/127.0.0.1:38364_jxf%2Fdb Error:KeeperErrorCode =
>>> NoNode for /solr/live_nodes/127.0.0.1:38364_jxf%2Fdb
>>>> [junit4:junit4]   2> 7544 T2684 oascc.SolrZkClient.makePath makePath:
>>> /live_nodes/127.0.0.1:38364_jxf%2Fdb
>>>> [junit4:junit4]   2> 7546 T2725 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> 7546 T2712 oascc.ZkStateReader$3.process Updating
>> live
>>> nodes... (3)
>>>> [junit4:junit4]   2> 7546 T2706 oascc.ZkStateReader$3.process Updating
>> live
>>> nodes... (3)
>>>> [junit4:junit4]   2> 7547 T2712 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> 7547 T2706 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> 7547 T2725 oascc.ZkStateReader$3.process Updating
>> live
>>> nodes... (3)
>>>> [junit4:junit4]   2> 7550 T2684
>>> oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating
>>> cluster state from ZooKeeper...
>>>> [junit4:junit4]   2> 7575 T2741 oasc.CoreContainer.create Creating
>> SolrCore
>>> 'collection1' using instanceDir: /usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-
>>> 1357312124870/collection1
>>>> [junit4:junit4]   2> 7576 T2741 oasc.ZkController.createCollectionZkNode
>>> Check for collection zkNode:collection1
>>>> [junit4:junit4]   2> 7577 T2741 oasc.ZkController.createCollectionZkNode
>>> Collection zkNode exists
>>>> [junit4:junit4]   2> 7577 T2741 oasc.ZkController.readConfigName Load
>>> collection config from:/collections/collection1
>>>> [junit4:junit4]   2> 7578 T2741 oasc.SolrResourceLoader.<init> new
>>> SolrResourceLoader for directory: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-
>>> 1357312124870/collection1/'
>>>> [junit4:junit4]   2> 7579 T2741
>> oasc.SolrResourceLoader.replaceClassLoader
>>> Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty2-
>>> 1357312124870/collection1/lib/README' to classloader
>>>> [junit4:junit4]   2> 7579 T2741
>> oasc.SolrResourceLoader.replaceClassLoader
>>> Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty2-
>>> 1357312124870/collection1/lib/classes/' to classloader
>>>> [junit4:junit4]   2> 7616 T2741 oasc.SolrConfig.<init> Using Lucene
>>> MatchVersion: LUCENE_41
>>>> [junit4:junit4]   2> 7664 T2741 oasc.SolrConfig.<init> Loaded SolrConfig:
>>> solrconfig.xml
>>>> [junit4:junit4]   2> 7765 T2741 oass.IndexSchema.readSchema Reading
>> Solr
>>> Schema
>>>> [junit4:junit4]   2> 7769 T2741 oass.IndexSchema.readSchema Schema
>>> name=test
>>>> [junit4:junit4]   2> 8186 T2741 oass.OpenExchangeRatesOrgProvider.init
>>> Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>>>> [junit4:junit4]   2> 8193 T2741 oass.IndexSchema.readSchema default
>>> search field in schema is text
>>>> [junit4:junit4]   2> 8196 T2741 oass.IndexSchema.readSchema unique key
>>> field: id
>>>> [junit4:junit4]   2> 8208 T2741 oass.FileExchangeRateProvider.reload
>>> Reloading exchange rates from file currency.xml
>>>> [junit4:junit4]   2> 8212 T2741 oass.FileExchangeRateProvider.reload
>>> Reloading exchange rates from file currency.xml
>>>> [junit4:junit4]   2> 8215 T2741
>> oass.OpenExchangeRatesOrgProvider.reload
>>> Reloading exchange rates from open-exchange-rates.json
>>>> [junit4:junit4]   2> 8217 T2741
>> oass.OpenExchangeRatesOrgProvider.reload
>>> Reloading exchange rates from open-exchange-rates.json
>>>> [junit4:junit4]   2> 8218 T2741 oasc.SolrCore.<init> [collection1] Opening
>>> new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-
>> Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-
>>> 1357312124870/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/
>>>> [junit4:junit4]   2> 8218 T2741 oasc.JmxMonitoredMap.<init> JMX
>>> monitoring is enabled. Adding Solr mbeans to JMX Server:
>>> com.sun.jmx.mbeanserver.JmxMBeanServer@2089208e
>>>> [junit4:junit4]   2> 8218 T2741 oasc.SolrCore.initDirectoryFactory
>>> solr.StandardDirectoryFactory
>>>> [junit4:junit4]   2> 8219 T2741 oasc.CachingDirectoryFactory.get return
>> new
>>> directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1357312117664/jetty2
>>> forceNew:false
>>>> [junit4:junit4]   2> 8220 T2741 oasc.CachingDirectoryFactory.close
>> Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2
>>>> [junit4:junit4]   2> 8220 T2741 oasc.SolrCore.getNewIndexDir New index
>>> directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/index/
>>>> [junit4:junit4]   2> 8220 T2741 oasc.SolrCore.initIndex WARNING
>>> [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/index' doesn't exist. Creating new index...
>>>> [junit4:junit4]   2> 8221 T2741 oasc.CachingDirectoryFactory.get return
>> new
>>> directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/index forceNew:false
>>>> [junit4:junit4]   2> 8255 T2741 oasc.SolrDeletionPolicy.onCommit
>>> SolrDeletionPolicy.onCommit: commits:num=1
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/index
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@4646d261),segF
>>> N=segments_1,generation=1,filenames=[segments_1]
>>>> [junit4:junit4]   2> 8256 T2741 oasc.SolrDeletionPolicy.updateCommits
>>> newest commit = 1[segments_1]
>>>> [junit4:junit4]   2> 8256 T2741 oasc.CachingDirectoryFactory.close
>> Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/index
>>>> [junit4:junit4]   2> 8256 T2741 oasc.SolrCore.initWriters created xml:
>>> solr.XMLResponseWriter
>>>> [junit4:junit4]   2> 8258 T2741 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "dedupe"
>>>> [junit4:junit4]   2> 8258 T2741 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "dedupe-allfields"
>>>> [junit4:junit4]   2> 8259 T2741 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "stored_sig"
>>>> [junit4:junit4]   2> 8259 T2741 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "uniq-fields"
>>>> [junit4:junit4]   2> 8259 T2741 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "distrib-dup-test-chain-implicit"
>>>> [junit4:junit4]   2> 8260 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler:
>>> solr.ReplicationHandler
>>>> [junit4:junit4]   2> 8260 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created /replication:
>>> solr.ReplicationHandler
>>>> [junit4:junit4]   2> 8260 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created standard:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 8261 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created /get:
>>> solr.RealTimeGetHandler
>>>> [junit4:junit4]   2> 8261 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created dismax:
>>> solr.SearchHandler
>>>> [junit4:junit4]   2> 8262 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created mock:
>>> org.apache.solr.core.MockQuerySenderListenerReqHandler
>>>> [junit4:junit4]   2> 8262 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created /admin/:
>>> org.apache.solr.handler.admin.AdminHandlers
>>>> [junit4:junit4]   2> 8262 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created defaults:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 8262 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 8263 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created lazy:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 8263 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created /update:
>>> solr.UpdateRequestHandler
>>>> [junit4:junit4]   2> 8264 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created /terms:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 8264 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 8264 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created
>>> spellCheckCompRH_Direct:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 8265 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created
>>> spellCheckWithWordbreak:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 8265 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created
>>> spellCheckWithWordbreak_Direct:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 8266 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created
>> spellCheckCompRH1:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 8266 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created mltrh:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 8266 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created tvrh:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 8267 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created /mlt:
>>> solr.MoreLikeThisHandler
>>>> [junit4:junit4]   2> 8267 T2741
>>> oasc.RequestHandlers.initHandlersFromConfig created /debug/dump:
>>> solr.DumpRequestHandler
>>>> [junit4:junit4]   2> 8276 T2741 oashl.XMLLoader.init
>>> xsltCacheLifetimeSeconds=60
>>>> [junit4:junit4]   2> 8279 T2741 oasc.SolrCore.initDeprecatedSupport
>>> WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please
>>> update your config to use the ShowFileRequestHandler.
>>>> [junit4:junit4]   2> 8280 T2741 oasc.SolrCore.initDeprecatedSupport
>>> WARNING adding ShowFileRequestHandler with hidden files:
>> [SCHEMA.XML,
>>> OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-
>>> EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-
>>> ISOLATIN1ACCENT.TXT]
>>>> [junit4:junit4]   2> 8282 T2741 oasc.CachingDirectoryFactory.close
>> Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2
>>>> [junit4:junit4]   2> 8283 T2741 oass.SolrIndexSearcher.<init> Opening
>>> Searcher@6900e433 main
>>>> [junit4:junit4]   2> 8284 T2741 oasu.CommitTracker.<init> Hard
>>> AutoCommit: disabled
>>>> [junit4:junit4]   2> 8284 T2741 oasu.CommitTracker.<init> Soft
>> AutoCommit:
>>> disabled
>>>> [junit4:junit4]   2> 8284 T2741 oashc.SpellCheckComponent.inform
>>> Initializing spell checkers
>>>> [junit4:junit4]   2> 8290 T2741 oass.DirectSolrSpellChecker.init init:
>>> 
>> {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLe
>>> ngth=3}
>>>> [junit4:junit4]   2> 8339 T2742 oasc.SolrCore.registerSearcher [collection1]
>>> Registered new searcher Searcher@6900e433
>>> main{StandardDirectoryReader(segments_1:1)}
>>>> [junit4:junit4]   2> 8342 T2741 oasc.ZkController.publish publishing
>>> core=collection1 state=down
>>>> [junit4:junit4]   2> 8342 T2741 oasc.ZkController.publish numShards not
>>> found on descriptor - reading it from system property
>>>> [junit4:junit4]   2> 8663 T2707 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 8664 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Update state
>>> numShards=1 message={
>>>> [junit4:junit4]   2>      "operation":"state",
>>>> [junit4:junit4]   2>      "numShards":"1",
>>>> [junit4:junit4]   2>      "shard":"shard1",
>>>> [junit4:junit4]   2>      "roles":null,
>>>> [junit4:junit4]   2>      "state":"active",
>>>> [junit4:junit4]   2>      "core":"collection1",
>>>> [junit4:junit4]   2>      "collection":"collection1",
>>>> [junit4:junit4]   2>      "node_name":"127.0.0.1:32591_jxf%2Fdb",
>>>> [junit4:junit4]   2>      "base_url":"http://127.0.0.1:32591/jxf/db"}
>>>> [junit4:junit4]   2> 8668 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Update state
>>> numShards=1 message={
>>>> [junit4:junit4]   2>      "operation":"state",
>>>> [junit4:junit4]   2>      "numShards":"1",
>>>> [junit4:junit4]   2>      "shard":null,
>>>> [junit4:junit4]   2>      "roles":null,
>>>> [junit4:junit4]   2>      "state":"down",
>>>> [junit4:junit4]   2>      "core":"collection1",
>>>> [junit4:junit4]   2>      "collection":"collection1",
>>>> [junit4:junit4]   2>      "node_name":"127.0.0.1:38364_jxf%2Fdb",
>>>> [junit4:junit4]   2>      "base_url":"http://127.0.0.1:38364/jxf/db"}
>>>> [junit4:junit4]   2> 8668 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Collection already exists
>>> with numShards=1
>>>> [junit4:junit4]   2> 8668 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to
>>> shard shard=shard1
>>>> [junit4:junit4]   2> 8681 T2712 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> 8681 T2706 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> 8681 T2725 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> 8681 T2740 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> 9345 T2741 oasc.CoreContainer.registerCore registering
>>> core: collection1
>>>> [junit4:junit4]   2> 9345 T2741 oasc.ZkController.register Register replica -
>>> core:collection1 address:http://127.0.0.1:38364/jxf/db
>> collection:collection1
>>> shard:shard1
>>>> [junit4:junit4]   2> 9357 T2741 oasc.ZkController.register We are
>>> http://127.0.0.1:38364/jxf/db/collection1/ and leader is
>>> http://127.0.0.1:32591/jxf/db/collection1/
>>>> [junit4:junit4]   2> 9357 T2741 oasc.ZkController.register No LogReplay
>>> needed for core=collection1 baseURL=http://127.0.0.1:38364/jxf/db
>>>> [junit4:junit4]   2> 9357 T2741 oasc.ZkController.checkRecovery Core
>> needs
>>> to recover:collection1
>>>> [junit4:junit4]   2> 9357 T2741 oasu.DefaultSolrCoreState.doRecovery
>>> Running recovery - first canceling any ongoing recovery
>>>> [junit4:junit4]   2> ASYNC  NEW_CORE C173 name=collection1
>>> org.apache.solr.core.SolrCore@4f17a619
>>> url=http://127.0.0.1:38364/jxf/db/collection1
>>> node=127.0.0.1:38364_jxf%2Fdb C173_STATE=coll:collection1
>>> core:collection1 props:{shard=null, roles=null, state=down,
>> core=collection1,
>>> collection=collection1, node_name=127.0.0.1:38364_jxf%2Fdb,
>>> base_url=http://127.0.0.1:38364/jxf/db}
>>>> [junit4:junit4]   2> 9358 T2743 C173 P38364 oasc.RecoveryStrategy.run
>>> Starting recovery process.  core=collection1 recoveringAfterStartup=true
>>>> [junit4:junit4]   2> 9358 T2741 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 9359 T2743 C173 P38364
>>> oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
>>>> [junit4:junit4]   2> 9359 T2743 C173 P38364 oasc.ZkController.publish
>>> publishing core=collection1 state=recovering
>>>> [junit4:junit4]   2> 9360 T2743 C173 P38364 oasc.ZkController.publish
>>> numShards not found on descriptor - reading it from system property
>>>> [junit4:junit4]   2> 9360 T2684 oass.SolrDispatchFilter.init
>>> user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1
>>>> [junit4:junit4]   2> 9361 T2684 oass.SolrDispatchFilter.init
>>> SolrDispatchFilter.init() done
>>>> [junit4:junit4]   2> 9361 T2684 oascsi.HttpClientUtil.createClient Creating
>>> new http client,
>>> 
>> config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=
>>> false
>>>> [junit4:junit4]   2> 9363 T2743 C173 P38364
>> oascsi.HttpClientUtil.createClient
>>> Creating new http client,
>>> 
>> config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=
>>> false
>>>> [junit4:junit4]   2> 9545 T2684 oejs.Server.doStart jetty-8.1.8.v20121106
>>>> [junit4:junit4]   2> 9548 T2684 oejs.AbstractConnector.doStart Started
>>> SocketConnector@127.0.0.1:46036
>>>> [junit4:junit4]   2> 9548 T2684 oasc.SolrResourceLoader.locateSolrHome
>>> JNDI not configured for solr (NoInitialContextEx)
>>>> [junit4:junit4]   2> 9549 T2684 oasc.SolrResourceLoader.locateSolrHome
>>> using system property solr.solr.home: /usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1357312127038
>>>> [junit4:junit4]   2> 9550 T2684 oasc.SolrResourceLoader.<init> new
>>> SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1357312127038/'
>>>> [junit4:junit4]   2> 9593 T2684 oass.SolrDispatchFilter.init
>>> SolrDispatchFilter.init()
>>>> [junit4:junit4]   2> 9594 T2684 oasc.SolrResourceLoader.locateSolrHome
>>> JNDI not configured for solr (NoInitialContextEx)
>>>> [junit4:junit4]   2> 9594 T2684 oasc.SolrResourceLoader.locateSolrHome
>>> using system property solr.solr.home: /usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1357312127038
>>>> [junit4:junit4]   2> 9595 T2684 oasc.CoreContainer$Initializer.initialize
>>> looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-
>>> Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-
>>> 1357312127038/solr.xml
>>>> [junit4:junit4]   2> 9595 T2684 oasc.CoreContainer.<init> New
>>> CoreContainer 1803842221
>>>> [junit4:junit4]   2> 9596 T2684 oasc.CoreContainer.load Loading
>>> CoreContainer using Solr Home: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1357312127038/'
>>> 
>>>> [junit4:junit4]   2> 9597 T2684 oasc.SolrResourceLoader.<init> new
>>> SolrResourceLoader for directory: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1357312127038/'
>>>> [junit4:junit4]   2> 9627 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to:
>>> 30000
>>>> [junit4:junit4]   2> 9628 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
>> http://
>>>> [junit4:junit4]   2> 9628 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to:
>>> 15000
>>>> [junit4:junit4]   2> 9629 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting
>>> maxConnectionsPerHost to: 20
>>>> [junit4:junit4]   2> 9629 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
>>>> [junit4:junit4]   2> 9630 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize
>> to:
>>> 2147483647
>>>> [junit4:junit4]   2> 9630 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime
>>> to: 5
>>>> [junit4:junit4]   2> 9631 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
>>>> [junit4:junit4]   2> 9631 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to:
>> false
>>>> [junit4:junit4]   2> 9632 T2684 oascsi.HttpClientUtil.createClient Creating
>>> new http client,
>>> 
>> config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout
>>> =30000&connTimeout=15000&retry=false
>>>> [junit4:junit4]   2> 9653 T2684 oasc.CoreContainer.load Registering Log
>>> Listener
>>>> [junit4:junit4]   2> 9692 T2684 oasc.CoreContainer.initZooKeeper
>>> Zookeeper client=127.0.0.1:24224/solr
>>>> [junit4:junit4]   2> 9693 T2684 oasc.ZkController.checkChrootPath zkHost
>>> includes chroot
>>>> [junit4:junit4]   2> 9693 T2684 oaz.ZooKeeper.<init> Initiating client
>>> connection, connectString=127.0.0.1:24224 sessionTimeout=60000
>>> watcher=org.apache.solr.common.cloud.ConnectionManager@412960ff
>>>> [junit4:junit4]   2> 9694 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Waiting for client to connect to ZooKeeper
>>>> [junit4:junit4]   2> 9695 T2753
>> oaz.ClientCnxn$SendThread.logStartConnect
>>> Opening socket connection to server localhost/127.0.0.1:24224. Will not
>>> attempt to authenticate using SASL (access denied
>>> ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
>>>> [junit4:junit4]   2> 9695 T2753
>>> oaz.ClientCnxn$SendThread.primeConnection Socket connection
>> established
>>> to localhost/127.0.0.1:24224, initiating session
>>>> [junit4:junit4]   2> 9696 T2686 oazs.NIOServerCnxnFactory.run Accepted
>>> socket connection from /140.211.11.196:30763
>>>> [junit4:junit4]   2> 9696 T2686
>>> oazs.ZooKeeperServer.processConnectRequest Client attempting to
>>> establish new session at /140.211.11.196:30763
>>>> [junit4:junit4]   2> 9698 T2688 oazs.ZooKeeperServer.finishSessionInit
>>> Established session 0x13c061b4ba60009 with negotiated timeout 20000 for
>>> client /140.211.11.196:30763
>>>> [junit4:junit4]   2> 9698 T2753 oaz.ClientCnxn$SendThread.onConnected
>>> Session establishment complete on server localhost/127.0.0.1:24224,
>>> sessionid = 0x13c061b4ba60009, negotiated timeout = 20000
>>>> [junit4:junit4]   2> 9698 T2754 oascc.ConnectionManager.process Watcher
>>> org.apache.solr.common.cloud.ConnectionManager@412960ff
>>> name:ZooKeeperConnection Watcher:127.0.0.1:24224 got event
>>> WatchedEvent state:SyncConnected type:None path:null path:null
>>> type:None
>>>> [junit4:junit4]   2> 9698 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Client is connected to ZooKeeper
>>>> [junit4:junit4]   2> 9700 T2689 oazs.PrepRequestProcessor.pRequest2Txn
>>> Processed session termination for sessionid: 0x13c061b4ba60009
>>>> [junit4:junit4]   2> 9713 T2754 oaz.ClientCnxn$EventThread.run
>>> EventThread shut down
>>>> [junit4:junit4]   2> 9713 T2686 oazs.NIOServerCnxn.closeSock Closed
>> socket
>>> connection for client /140.211.11.196:30763 which had sessionid
>>> 0x13c061b4ba60009
>>>> [junit4:junit4]   2> 9713 T2684 oaz.ZooKeeper.close Session:
>>> 0x13c061b4ba60009 closed
>>>> [junit4:junit4]   2> 9714 T2684 oascsi.HttpClientUtil.createClient Creating
>>> new http client,
>>> 
>> config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=
>>> 15000&connTimeout=30000
>>>> [junit4:junit4]   2> 9725 T2684 oaz.ZooKeeper.<init> Initiating client
>>> connection, connectString=127.0.0.1:24224/solr sessionTimeout=30000
>>> watcher=org.apache.solr.common.cloud.ConnectionManager@283a2015
>>>> [junit4:junit4]   2> 9726 T2755
>> oaz.ClientCnxn$SendThread.logStartConnect
>>> Opening socket connection to server localhost/127.0.0.1:24224. Will not
>>> attempt to authenticate using SASL (access denied
>>> ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
>>>> [junit4:junit4]   2> 9726 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Waiting for client to connect to ZooKeeper
>>>> [junit4:junit4]   2> 9727 T2755
>>> oaz.ClientCnxn$SendThread.primeConnection Socket connection
>> established
>>> to localhost/127.0.0.1:24224, initiating session
>>>> [junit4:junit4]   2> 9727 T2686 oazs.NIOServerCnxnFactory.run Accepted
>>> socket connection from /140.211.11.196:12579
>>>> [junit4:junit4]   2> 9727 T2686
>>> oazs.ZooKeeperServer.processConnectRequest Client attempting to
>>> establish new session at /140.211.11.196:12579
>>>> [junit4:junit4]   2> 9728 T2688 oazs.ZooKeeperServer.finishSessionInit
>>> Established session 0x13c061b4ba6000a with negotiated timeout 20000 for
>>> client /140.211.11.196:12579
>>>> [junit4:junit4]   2> 9728 T2755 oaz.ClientCnxn$SendThread.onConnected
>>> Session establishment complete on server localhost/127.0.0.1:24224,
>>> sessionid = 0x13c061b4ba6000a, negotiated timeout = 20000
>>>> [junit4:junit4]   2> 9729 T2756 oascc.ConnectionManager.process Watcher
>>> org.apache.solr.common.cloud.ConnectionManager@283a2015
>>> name:ZooKeeperConnection Watcher:127.0.0.1:24224/solr got event
>>> WatchedEvent state:SyncConnected type:None path:null path:null
>>> type:None
>>>> [junit4:junit4]   2> 9729 T2684
>> oascc.ConnectionManager.waitForConnected
>>> Client is connected to ZooKeeper
>>>> [junit4:junit4]   2> 9730 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba6000a
>>> type:create cxid:0x1 zxid:0x7e txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer Error:KeeperErrorCode = NodeExists for
>> /solr/overseer
>>>> [junit4:junit4]   2> 9736 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba6000a
>>> type:create cxid:0x2 zxid:0x7f txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer Error:KeeperErrorCode = NodeExists for
>> /solr/overseer
>>>> [junit4:junit4]   2> 9737 T2684
>> oasc.ZkController.createEphemeralLiveNode
>>> Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46036_jxf%2Fdb
>>>> [junit4:junit4]   2> 9738 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba6000a
>>> type:delete cxid:0x4 zxid:0x80 txntype:-1 reqpath:n/a Error
>>> Path:/solr/live_nodes/127.0.0.1:46036_jxf%2Fdb Error:KeeperErrorCode =
>>> NoNode for /solr/live_nodes/127.0.0.1:46036_jxf%2Fdb
>>>> [junit4:junit4]   2> 9744 T2684 oascc.SolrZkClient.makePath makePath:
>>> /live_nodes/127.0.0.1:46036_jxf%2Fdb
>>>> [junit4:junit4]   2> 9746 T2725 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> 9747 T2740 oascc.ZkStateReader$3.process Updating
>> live
>>> nodes... (4)
>>>> [junit4:junit4]   2> 9747 T2740 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> 9747 T2706 oascc.ZkStateReader$3.process Updating
>> live
>>> nodes... (4)
>>>> [junit4:junit4]   2> 9747 T2712 oascc.ZkStateReader$3.process Updating
>> live
>>> nodes... (4)
>>>> [junit4:junit4]   2> 9747 T2706 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> 9747 T2712 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> 9749 T2725 oascc.ZkStateReader$3.process Updating
>> live
>>> nodes... (4)
>>>> [junit4:junit4]   2> 9750 T2684
>>> oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating
>>> cluster state from ZooKeeper...
>>>> [junit4:junit4]   2> 9757 T2757 oasc.CoreContainer.create Creating
>> SolrCore
>>> 'collection1' using instanceDir: /usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-
>>> 1357312127038/collection1
>>>> [junit4:junit4]   2> 9758 T2757 oasc.ZkController.createCollectionZkNode
>>> Check for collection zkNode:collection1
>>>> [junit4:junit4]   2> 9758 T2757 oasc.ZkController.createCollectionZkNode
>>> Collection zkNode exists
>>>> [junit4:junit4]   2> 9759 T2757 oasc.ZkController.readConfigName Load
>>> collection config from:/collections/collection1
>>>> [junit4:junit4]   2> 9760 T2757 oasc.SolrResourceLoader.<init> new
>>> SolrResourceLoader for directory: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-
>>> 1357312127038/collection1/'
>>>> [junit4:junit4]   2> 9761 T2757
>> oasc.SolrResourceLoader.replaceClassLoader
>>> Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty3-
>>> 1357312127038/collection1/lib/README' to classloader
>>>> [junit4:junit4]   2> 9762 T2757
>> oasc.SolrResourceLoader.replaceClassLoader
>>> Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty3-
>>> 1357312127038/collection1/lib/classes/' to classloader
>>>> [junit4:junit4]   2> 9814 T2757 oasc.SolrConfig.<init> Using Lucene
>>> MatchVersion: LUCENE_41
>>>> [junit4:junit4]   2> 9884 T2757 oasc.SolrConfig.<init> Loaded SolrConfig:
>>> solrconfig.xml
>>>> [junit4:junit4]   2> 9985 T2757 oass.IndexSchema.readSchema Reading
>> Solr
>>> Schema
>>>> [junit4:junit4]   2> 9991 T2757 oass.IndexSchema.readSchema Schema
>>> name=test
>>>> [junit4:junit4]   2> 10195 T2707 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 10196 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Update state
>>> numShards=1 message={
>>>> [junit4:junit4]   2>      "operation":"state",
>>>> [junit4:junit4]   2>      "numShards":"1",
>>>> [junit4:junit4]   2>      "shard":"shard1",
>>>> [junit4:junit4]   2>      "roles":null,
>>>> [junit4:junit4]   2>      "state":"recovering",
>>>> [junit4:junit4]   2>      "core":"collection1",
>>>> [junit4:junit4]   2>      "collection":"collection1",
>>>> [junit4:junit4]   2>      "node_name":"127.0.0.1:38364_jxf%2Fdb",
>>>> [junit4:junit4]   2>      "base_url":"http://127.0.0.1:38364/jxf/db"}
>>>> [junit4:junit4]   2> 10211 T2712 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> 10211 T2756 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> 10211 T2740 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> 10211 T2725 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> 10212 T2706 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> 10601 T2757 oass.OpenExchangeRatesOrgProvider.init
>>> Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>>>> [junit4:junit4]   2> 10613 T2757 oass.IndexSchema.readSchema default
>>> search field in schema is text
>>>> [junit4:junit4]   2> 10617 T2757 oass.IndexSchema.readSchema unique
>> key
>>> field: id
>>>> [junit4:junit4]   2> 10631 T2757 oass.FileExchangeRateProvider.reload
>>> Reloading exchange rates from file currency.xml
>>>> [junit4:junit4]   2> 10636 T2757 oass.FileExchangeRateProvider.reload
>>> Reloading exchange rates from file currency.xml
>>>> [junit4:junit4]   2> 10640 T2757
>>> oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates
>> from
>>> open-exchange-rates.json
>>>> [junit4:junit4]   2> 10641 T2757
>>> oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates
>> from
>>> open-exchange-rates.json
>>>> [junit4:junit4]   2> 10643 T2757 oasc.SolrCore.<init> [collection1] Opening
>>> new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-
>> Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-
>>> 1357312127038/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/
>>>> [junit4:junit4]   2> 10643 T2757 oasc.JmxMonitoredMap.<init> JMX
>>> monitoring is enabled. Adding Solr mbeans to JMX Server:
>>> com.sun.jmx.mbeanserver.JmxMBeanServer@2089208e
>>>> [junit4:junit4]   2> 10644 T2757 oasc.SolrCore.initDirectoryFactory
>>> solr.StandardDirectoryFactory
>>>> [junit4:junit4]   2> 10644 T2757 oasc.CachingDirectoryFactory.get return
>>> new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-
>>> Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1357312117664/jetty3
>>> forceNew:false
>>>> [junit4:junit4]   2> 10645 T2757 oasc.CachingDirectoryFactory.close
>>> Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-
>>> Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1357312117664/jetty3
>>>> [junit4:junit4]   2> 10645 T2757 oasc.SolrCore.getNewIndexDir New index
>>> directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/index/
>>>> [junit4:junit4]   2> 10646 T2757 oasc.SolrCore.initIndex WARNING
>>> [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/index' doesn't exist. Creating new index...
>>>> [junit4:junit4]   2> 10647 T2757 oasc.CachingDirectoryFactory.get return
>>> new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-
>>> Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/index forceNew:false
>>>> [junit4:junit4]   2> 10653 T2757 oasc.SolrDeletionPolicy.onCommit
>>> SolrDeletionPolicy.onCommit: commits:num=1
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/index
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@79b8c6a1),segF
>>> N=segments_1,generation=1,filenames=[segments_1]
>>>> [junit4:junit4]   2> 10653 T2757 oasc.SolrDeletionPolicy.updateCommits
>>> newest commit = 1[segments_1]
>>>> [junit4:junit4]   2> 10654 T2757 oasc.CachingDirectoryFactory.close
>>> Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-
>>> Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/index
>>>> [junit4:junit4]   2> 10654 T2757 oasc.SolrCore.initWriters created xml:
>>> solr.XMLResponseWriter
>>>> [junit4:junit4]   2> 10656 T2757 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "dedupe"
>>>> [junit4:junit4]   2> 10657 T2757 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "dedupe-allfields"
>>>> [junit4:junit4]   2> 10657 T2757 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "stored_sig"
>>>> [junit4:junit4]   2> 10658 T2757 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "uniq-fields"
>>>> [junit4:junit4]   2> 10658 T2757 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "distrib-dup-test-chain-implicit"
>>>> [junit4:junit4]   2> 10659 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler:
>>> solr.ReplicationHandler
>>>> [junit4:junit4]   2> 10659 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created /replication:
>>> solr.ReplicationHandler
>>>> [junit4:junit4]   2> 10660 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created standard:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 10660 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created /get:
>>> solr.RealTimeGetHandler
>>>> [junit4:junit4]   2> 10661 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created dismax:
>>> solr.SearchHandler
>>>> [junit4:junit4]   2> 10661 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created mock:
>>> org.apache.solr.core.MockQuerySenderListenerReqHandler
>>>> [junit4:junit4]   2> 10662 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created /admin/:
>>> org.apache.solr.handler.admin.AdminHandlers
>>>> [junit4:junit4]   2> 10663 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created defaults:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 10663 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 10663 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created lazy:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 10664 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created /update:
>>> solr.UpdateRequestHandler
>>>> [junit4:junit4]   2> 10664 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created /terms:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 10665 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 10666 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created
>>> spellCheckCompRH_Direct:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 10666 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created
>>> spellCheckWithWordbreak:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 10667 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created
>>> spellCheckWithWordbreak_Direct:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 10667 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created
>> spellCheckCompRH1:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 10668 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created mltrh:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 10668 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created tvrh:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 10669 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created /mlt:
>>> solr.MoreLikeThisHandler
>>>> [junit4:junit4]   2> 10670 T2757
>>> oasc.RequestHandlers.initHandlersFromConfig created /debug/dump:
>>> solr.DumpRequestHandler
>>>> [junit4:junit4]   2> 10683 T2757 oashl.XMLLoader.init
>>> xsltCacheLifetimeSeconds=60
>>>> [junit4:junit4]   2> 10687 T2757 oasc.SolrCore.initDeprecatedSupport
>>> WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please
>>> update your config to use the ShowFileRequestHandler.
>>>> [junit4:junit4]   2> 10688 T2757 oasc.SolrCore.initDeprecatedSupport
>>> WARNING adding ShowFileRequestHandler with hidden files:
>> [SCHEMA.XML,
>>> OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-
>>> EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-
>>> ISOLATIN1ACCENT.TXT]
>>>> [junit4:junit4]   2> 10691 T2757 oasc.CachingDirectoryFactory.close
>>> Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-
>>> Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1357312117664/jetty3
>>>> [junit4:junit4]   2> 10693 T2757 oass.SolrIndexSearcher.<init> Opening
>>> Searcher@4c68d8d0 main
>>>> [junit4:junit4]   2> 10694 T2757 oasu.CommitTracker.<init> Hard
>>> AutoCommit: disabled
>>>> [junit4:junit4]   2> 10694 T2757 oasu.CommitTracker.<init> Soft
>>> AutoCommit: disabled
>>>> [junit4:junit4]   2> 10695 T2757 oashc.SpellCheckComponent.inform
>>> Initializing spell checkers
>>>> [junit4:junit4]   2> 10709 T2757 oass.DirectSolrSpellChecker.init init:
>>> 
>> {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLe
>>> ngth=3}
>>>> [junit4:junit4]   2> 10855 T2758 oasc.SolrCore.registerSearcher
>> [collection1]
>>> Registered new searcher Searcher@4c68d8d0
>>> main{StandardDirectoryReader(segments_1:1)}
>>>> [junit4:junit4]   2> 10859 T2757 oasc.ZkController.publish publishing
>>> core=collection1 state=down
>>>> [junit4:junit4]   2> 10859 T2757 oasc.ZkController.publish numShards not
>>> found on descriptor - reading it from system property
>>>> [junit4:junit4]   2> 11718 T2707 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 11719 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Update state
>>> numShards=1 message={
>>>> [junit4:junit4]   2>      "operation":"state",
>>>> [junit4:junit4]   2>      "numShards":"1",
>>>> [junit4:junit4]   2>      "shard":null,
>>>> [junit4:junit4]   2>      "roles":null,
>>>> [junit4:junit4]   2>      "state":"down",
>>>> [junit4:junit4]   2>      "core":"collection1",
>>>> [junit4:junit4]   2>      "collection":"collection1",
>>>> [junit4:junit4]   2>      "node_name":"127.0.0.1:46036_jxf%2Fdb",
>>>> [junit4:junit4]   2>      "base_url":"http://127.0.0.1:46036/jxf/db"}
>>>> [junit4:junit4]   2> 11719 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Collection already exists
>>> with numShards=1
>>>> [junit4:junit4]   2> 11719 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to
>>> shard shard=shard1
>>>> [junit4:junit4]   2> 11738 T2725 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> 11738 T2756 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> 11738 T2712 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> 11738 T2706 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> 11738 T2740 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> 11862 T2757 oasc.CoreContainer.registerCore
>> registering
>>> core: collection1
>>>> [junit4:junit4]   2> 11862 T2757 oasc.ZkController.register Register replica -
>>> core:collection1 address:http://127.0.0.1:46036/jxf/db
>> collection:collection1
>>> shard:shard1
>>>> [junit4:junit4]   2> 11865 T2757 oasc.ZkController.register We are
>>> http://127.0.0.1:46036/jxf/db/collection1/ and leader is
>>> http://127.0.0.1:32591/jxf/db/collection1/
>>>> [junit4:junit4]   2> 11866 T2757 oasc.ZkController.register No LogReplay
>>> needed for core=collection1 baseURL=http://127.0.0.1:46036/jxf/db
>>>> [junit4:junit4]   2> 11866 T2757 oasc.ZkController.checkRecovery Core
>>> needs to recover:collection1
>>>> [junit4:junit4]   2> 11866 T2757 oasu.DefaultSolrCoreState.doRecovery
>>> Running recovery - first canceling any ongoing recovery
>>>> [junit4:junit4]   2> ASYNC  NEW_CORE C174 name=collection1
>>> org.apache.solr.core.SolrCore@30c17bd0
>>> url=http://127.0.0.1:46036/jxf/db/collection1
>>> node=127.0.0.1:46036_jxf%2Fdb C174_STATE=coll:collection1
>>> core:collection1 props:{shard=null, roles=null, state=down,
>> core=collection1,
>>> collection=collection1, node_name=127.0.0.1:46036_jxf%2Fdb,
>>> base_url=http://127.0.0.1:46036/jxf/db}
>>>> [junit4:junit4]   2> 11867 T2759 C174 P46036 oasc.RecoveryStrategy.run
>>> Starting recovery process.  core=collection1 recoveringAfterStartup=true
>>>> [junit4:junit4]   2> 11868 T2759 C174 P46036
>>> oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
>>>> [junit4:junit4]   2> 11867 T2757 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 11868 T2759 C174 P46036 oasc.ZkController.publish
>>> publishing core=collection1 state=recovering
>>>> [junit4:junit4]   2> 11868 T2759 C174 P46036 oasc.ZkController.publish
>>> numShards not found on descriptor - reading it from system property
>>>> [junit4:junit4]   2> 11869 T2684 oass.SolrDispatchFilter.init
>>> user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1
>>>> [junit4:junit4]   2> 11870 T2759 C174 P46036
>>> oascsi.HttpClientUtil.createClient Creating new http client,
>>> 
>> config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=
>>> false
>>>> [junit4:junit4]   2> 11870 T2684 oass.SolrDispatchFilter.init
>>> SolrDispatchFilter.init() done
>>>> [junit4:junit4]   2> 11870 T2684 oascsi.HttpClientUtil.createClient Creating
>>> new http client,
>>> 
>> config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=
>>> false
>>>> [junit4:junit4]   2> 12048 T2684 oejs.Server.doStart jetty-8.1.8.v20121106
>>>> [junit4:junit4]   2> 12051 T2684 oejs.AbstractConnector.doStart Started
>>> SocketConnector@127.0.0.1:20695
>>>> [junit4:junit4]   2> 12052 T2684 oasc.SolrResourceLoader.locateSolrHome
>>> JNDI not configured for solr (NoInitialContextEx)
>>>> [junit4:junit4]   2> 12052 T2684 oasc.SolrResourceLoader.locateSolrHome
>>> using system property solr.solr.home: /usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty4-1357312129542
>>>> [junit4:junit4]   2> 12053 T2684 oasc.SolrResourceLoader.<init> new
>>> SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty4-1357312129542/'
>>>> [junit4:junit4]   2> 12096 T2684 oass.SolrDispatchFilter.init
>>> SolrDispatchFilter.init()
>>>> [junit4:junit4]   2> 12097 T2684 oasc.SolrResourceLoader.locateSolrHome
>>> JNDI not configured for solr (NoInitialContextEx)
>>>> [junit4:junit4]   2> 12097 T2684 oasc.SolrResourceLoader.locateSolrHome
>>> using system property solr.solr.home: /usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty4-1357312129542
>>>> [junit4:junit4]   2> 12098 T2684 oasc.CoreContainer$Initializer.initialize
>>> looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-
>>> Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty4-
>>> 1357312129542/solr.xml
>>>> [junit4:junit4]   2> 12098 T2684 oasc.CoreContainer.<init> New
>>> CoreContainer 702970504
>>>> [junit4:junit4]   2> 12099 T2684 oasc.CoreContainer.load Loading
>>> CoreContainer using Solr Home: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty4-1357312129542/'
>>>> [junit4:junit4]   2> 12099 T2684 oasc.SolrResourceLoader.<init> new
>>> SolrResourceLoader for directory: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty4-1357312129542/'
>>>> [junit4:junit4]   2> 12130 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to:
>>> 30000
>>>> [junit4:junit4]   2> 12131 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
>> http://
>>>> [junit4:junit4]   2> 12131 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to:
>>> 15000
>>>> [junit4:junit4]   2> 12132 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting
>>> maxConnectionsPerHost to: 20
>>>> [junit4:junit4]   2> 12132 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
>>>> [junit4:junit4]   2> 12133 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize
>> to:
>>> 2147483647
>>>> [junit4:junit4]   2> 12133 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime
>>> to: 5
>>>> [junit4:junit4]   2> 12134 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
>>>> [junit4:junit4]   2> 12134 T2684
>>> oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to:
>> false
>>>> [junit4:junit4]   2> 12135 T2684 oascsi.HttpClientUtil.createClient Creating
>>> new http client,
>>> 
>> config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout
>>> =30000&connTimeout=15000&retry=false
>>>> [junit4:junit4]   2> 12172 T2684 oasc.CoreContainer.load Registering Log
>>> Listener
>>>> [junit4:junit4]   2> 12192 T2684 oasc.CoreContainer.initZooKeeper
>>> Zookeeper client=127.0.0.1:24224/solr
>>>> [junit4:junit4]   2> 12193 T2684 oasc.ZkController.checkChrootPath zkHost
>>> includes chroot
>>>> [junit4:junit4]   2> 12193 T2684 oaz.ZooKeeper.<init> Initiating client
>>> connection, connectString=127.0.0.1:24224 sessionTimeout=60000
>>> watcher=org.apache.solr.common.cloud.ConnectionManager@786e6129
>>>> [junit4:junit4]   2> 12194 T2684
>>> oascc.ConnectionManager.waitForConnected Waiting for client to connect
>> to
>>> ZooKeeper
>>>> [junit4:junit4]   2> 12195 T2769
>>> oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to
>>> server localhost/127.0.0.1:24224. Will not attempt to authenticate using
>> SASL
>>> (access denied ("javax.security.auth.AuthPermission"
>>> "getLoginConfiguration"))
>>>> [junit4:junit4]   2> 12195 T2769
>>> oaz.ClientCnxn$SendThread.primeConnection Socket connection
>> established
>>> to localhost/127.0.0.1:24224, initiating session
>>>> [junit4:junit4]   2> 12196 T2686 oazs.NIOServerCnxnFactory.run Accepted
>>> socket connection from /140.211.11.196:63322
>>>> [junit4:junit4]   2> 12196 T2686
>>> oazs.ZooKeeperServer.processConnectRequest Client attempting to
>>> establish new session at /140.211.11.196:63322
>>>> [junit4:junit4]   2> 12198 T2688 oazs.ZooKeeperServer.finishSessionInit
>>> Established session 0x13c061b4ba6000b with negotiated timeout 20000 for
>>> client /140.211.11.196:63322
>>>> [junit4:junit4]   2> 12198 T2769 oaz.ClientCnxn$SendThread.onConnected
>>> Session establishment complete on server localhost/127.0.0.1:24224,
>>> sessionid = 0x13c061b4ba6000b, negotiated timeout = 20000
>>>> [junit4:junit4]   2> 12198 T2770 oascc.ConnectionManager.process
>> Watcher
>>> org.apache.solr.common.cloud.ConnectionManager@786e6129
>>> name:ZooKeeperConnection Watcher:127.0.0.1:24224 got event
>>> WatchedEvent state:SyncConnected type:None path:null path:null
>>> type:None
>>>> [junit4:junit4]   2> 12199 T2684
>>> oascc.ConnectionManager.waitForConnected Client is connected to
>>> ZooKeeper
>>>> [junit4:junit4]   2> 12200 T2689
>> oazs.PrepRequestProcessor.pRequest2Txn
>>> Processed session termination for sessionid: 0x13c061b4ba6000b
>>>> [junit4:junit4]   2> 12208 T2770 oaz.ClientCnxn$EventThread.run
>>> EventThread shut down
>>>> [junit4:junit4]   2> 12208 T2686 oazs.NIOServerCnxn.closeSock Closed
>>> socket connection for client /140.211.11.196:63322 which had sessionid
>>> 0x13c061b4ba6000b
>>>> [junit4:junit4]   2> 12208 T2684 oaz.ZooKeeper.close Session:
>>> 0x13c061b4ba6000b closed
>>>> [junit4:junit4]   2> 12209 T2684 oascsi.HttpClientUtil.createClient Creating
>>> new http client,
>>> 
>> config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=
>>> 15000&connTimeout=30000
>>>> [junit4:junit4]   2> 12218 T2684 oaz.ZooKeeper.<init> Initiating client
>>> connection, connectString=127.0.0.1:24224/solr sessionTimeout=30000
>>> watcher=org.apache.solr.common.cloud.ConnectionManager@308ccd22
>>>> [junit4:junit4]   2> 12219 T2771
>>> oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to
>>> server localhost/127.0.0.1:24224. Will not attempt to authenticate using
>> SASL
>>> (access denied ("javax.security.auth.AuthPermission"
>>> "getLoginConfiguration"))
>>>> [junit4:junit4]   2> 12219 T2684
>>> oascc.ConnectionManager.waitForConnected Waiting for client to connect
>> to
>>> ZooKeeper
>>>> [junit4:junit4]   2> 12220 T2771
>>> oaz.ClientCnxn$SendThread.primeConnection Socket connection
>> established
>>> to localhost/127.0.0.1:24224, initiating session
>>>> [junit4:junit4]   2> 12220 T2686 oazs.NIOServerCnxnFactory.run Accepted
>>> socket connection from /140.211.11.196:47457
>>>> [junit4:junit4]   2> 12220 T2686
>>> oazs.ZooKeeperServer.processConnectRequest Client attempting to
>>> establish new session at /140.211.11.196:47457
>>>> [junit4:junit4]   2> 12221 T2688 oazs.ZooKeeperServer.finishSessionInit
>>> Established session 0x13c061b4ba6000c with negotiated timeout 20000 for
>>> client /140.211.11.196:47457
>>>> [junit4:junit4]   2> 12221 T2771 oaz.ClientCnxn$SendThread.onConnected
>>> Session establishment complete on server localhost/127.0.0.1:24224,
>>> sessionid = 0x13c061b4ba6000c, negotiated timeout = 20000
>>>> [junit4:junit4]   2> 12222 T2772 oascc.ConnectionManager.process
>> Watcher
>>> org.apache.solr.common.cloud.ConnectionManager@308ccd22
>>> name:ZooKeeperConnection Watcher:127.0.0.1:24224/solr got event
>>> WatchedEvent state:SyncConnected type:None path:null path:null
>>> type:None
>>>> [junit4:junit4]   2> 12222 T2684
>>> oascc.ConnectionManager.waitForConnected Client is connected to
>>> ZooKeeper
>>>> [junit4:junit4]   2> 12223 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba6000c
>>> type:create cxid:0x1 zxid:0x91 txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer Error:KeeperErrorCode = NodeExists for
>> /solr/overseer
>>>> [junit4:junit4]   2> 12224 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba6000c
>>> type:create cxid:0x2 zxid:0x92 txntype:-1 reqpath:n/a Error
>>> Path:/solr/overseer Error:KeeperErrorCode = NodeExists for
>> /solr/overseer
>>>> [junit4:junit4]   2> 12232 T2684
>>> oasc.ZkController.createEphemeralLiveNode Register node as live in
>>> ZooKeeper:/live_nodes/127.0.0.1:20695_jxf%2Fdb
>>>> [junit4:junit4]   2> 12233 T2689 oazs.PrepRequestProcessor.pRequest Got
>>> user-level KeeperException when processing sessionid:0x13c061b4ba6000c
>>> type:delete cxid:0x4 zxid:0x93 txntype:-1 reqpath:n/a Error
>>> Path:/solr/live_nodes/127.0.0.1:20695_jxf%2Fdb Error:KeeperErrorCode =
>>> NoNode for /solr/live_nodes/127.0.0.1:20695_jxf%2Fdb
>>>> [junit4:junit4]   2> 12234 T2684 oascc.SolrZkClient.makePath makePath:
>>> /live_nodes/127.0.0.1:20695_jxf%2Fdb
>>>> [junit4:junit4]   2> 12237 T2725 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> 12238 T2740 oascc.ZkStateReader$3.process Updating
>>> live nodes... (5)
>>>> [junit4:junit4]   2> 12238 T2712 oascc.ZkStateReader$3.process Updating
>>> live nodes... (5)
>>>> [junit4:junit4]   2> 12238 T2706 oascc.ZkStateReader$3.process Updating
>>> live nodes... (5)
>>>> [junit4:junit4]   2> 12238 T2756 oascc.ZkStateReader$3.process Updating
>>> live nodes... (5)
>>>> [junit4:junit4]   2> 12238 T2740 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> 12238 T2756 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> 12238 T2706 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> 12239 T2712 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> 12245 T2725 oascc.ZkStateReader$3.process Updating
>>> live nodes... (5)
>>>> [junit4:junit4]   2> 12246 T2684
>>> oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating
>>> cluster state from ZooKeeper...
>>>> [junit4:junit4]   2> 12253 T2773 oasc.CoreContainer.create Creating
>> SolrCore
>>> 'collection1' using instanceDir: /usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty4-
>>> 1357312129542/collection1
>>>> [junit4:junit4]   2> 12253 T2773 oasc.ZkController.createCollectionZkNode
>>> Check for collection zkNode:collection1
>>>> [junit4:junit4]   2> 12253 T2773 oasc.ZkController.createCollectionZkNode
>>> Collection zkNode exists
>>>> [junit4:junit4]   2> 12254 T2773 oasc.ZkController.readConfigName Load
>>> collection config from:/collections/collection1
>>>> [junit4:junit4]   2> 12255 T2773 oasc.SolrResourceLoader.<init> new
>>> SolrResourceLoader for directory: '/usr/home/hudson/hudson-
>>> slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty4-
>>> 1357312129542/collection1/'
>>>> [junit4:junit4]   2> 12256 T2773
>>> oasc.SolrResourceLoader.replaceClassLoader Adding
>>> 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> jetty4-1357312129542/collection1/lib/classes/' to classloader
>>>> [junit4:junit4]   2> 12257 T2773
>>> oasc.SolrResourceLoader.replaceClassLoader Adding
>>> 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> jetty4-1357312129542/collection1/lib/README' to classloader
>>>> [junit4:junit4]   2> 12310 T2773 oasc.SolrConfig.<init> Using Lucene
>>> MatchVersion: LUCENE_41
>>>> [junit4:junit4]   2> 12380 T2773 oasc.SolrConfig.<init> Loaded SolrConfig:
>>> solrconfig.xml
>>>> [junit4:junit4]   2>  C173_STATE=coll:collection1 core:collection1
>>> props:{shard=shard1, roles=null, state=recovering, core=collection1,
>>> collection=collection1, node_name=127.0.0.1:38364_jxf%2Fdb,
>>> base_url=http://127.0.0.1:38364/jxf/db}
>>>> [junit4:junit4]   2> 12382 T2743 C173 P38364
>>> oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from
>>> http://127.0.0.1:32591/jxf/db/collection1/ core=collection1 -
>>> recoveringAfterStartup=true
>>>> [junit4:junit4]   2> 12382 T2743 C173 P38364 oasu.PeerSync.sync
>> PeerSync:
>>> core=collection1 url=http://127.0.0.1:38364/jxf/db START
>>> replicas=[http://127.0.0.1:32591/jxf/db/collection1/] nUpdates=100
>>>> [junit4:junit4]   2> 12382 T2743 C173 P38364 oasu.PeerSync.sync
>> WARNING
>>> no frame of reference to tell of we've missed updates
>>>> [junit4:junit4]   2> 12383 T2743 C173 P38364
>>> oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful
>> -
>>> trying replication. core=collection1
>>>> [junit4:junit4]   2> 12383 T2743 C173 P38364
>>> oasc.RecoveryStrategy.doRecovery Starting Replication Recovery.
>>> core=collection1
>>>> [junit4:junit4]   2> 12383 T2743 C173 P38364
>>> oasc.RecoveryStrategy.doRecovery Begin buffering updates.
>>> core=collection1
>>>> [junit4:junit4]   2> 12383 T2743 C173 P38364
>>> oasu.UpdateLog.bufferUpdates Starting to buffer updates.
>>> FSUpdateLog{state=ACTIVE, tlog=null}
>>>> [junit4:junit4]   2> 12384 T2743 C173 P38364
>>> oasc.RecoveryStrategy.replicate Attempting to replicate from
>>> http://127.0.0.1:32591/jxf/db/collection1/. core=collection1
>>>> [junit4:junit4]   2> 12384 T2743 C173 P38364
>>> oascsi.HttpClientUtil.createClient Creating new http client,
>>> 
>> config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=
>>> false
>>>> [junit4:junit4]   2> ASYNC  NEW_CORE C175 name=collection1
>>> org.apache.solr.core.SolrCore@254b3117
>>> url=http://127.0.0.1:32591/jxf/db/collection1
>>> node=127.0.0.1:32591_jxf%2Fdb C175_STATE=coll:collection1
>>> core:collection1 props:{shard=shard1, roles=null, state=active,
>>> core=collection1, collection=collection1,
>>> node_name=127.0.0.1:32591_jxf%2Fdb,
>>> base_url=http://127.0.0.1:32591/jxf/db, leader=true}
>>>> [junit4:junit4]   2> 12389 T2717 C175 P32591 REQ /get
>>> {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0
>>> QTime=1
>>>> [junit4:junit4]   2> 12395 T2718 C175 P32591
>>> oasu.DirectUpdateHandler2.commit start
>>> 
>> commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDel
>>> etes=false,softCommit=false}
>>>> [junit4:junit4]   2> 12396 T2718 C175 P32591
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1
>>>> [junit4:junit4]   2> 12400 T2718 C175 P32591 oasc.SolrDeletionPolicy.onInit
>>> SolrDeletionPolicy.onInit: commits:num=1
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1/index
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@7556f92c),segFN
>>> =segments_1,generation=1,filenames=[segments_1]
>>>> [junit4:junit4]   2> 12400 T2718 C175 P32591
>>> oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
>>>> [junit4:junit4]   2> 12404 T2718 C175 P32591
>>> oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit:
>>> commits:num=2
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1/index
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@7556f92c),segFN
>>> =segments_1,generation=1,filenames=[segments_1]
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1/index
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@7556f92c),segFN
>>> =segments_2,generation=2,filenames=[segments_2]
>>>> [junit4:junit4]   2> 12404 T2718 C175 P32591
>>> oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
>>>> [junit4:junit4]   2> 12406 T2718 C175 P32591
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1
>>>> [junit4:junit4]   2> 12406 T2718 C175 P32591 oass.SolrIndexSearcher.<init>
>>> Opening Searcher@79950ac5 realtime
>>>> [junit4:junit4]   2> 12406 T2718 C175 P32591
>>> oasu.DirectUpdateHandler2.commit end_commit_flush
>>>> [junit4:junit4]   2> 12407 T2718 C175 P32591 /update
>>> 
>> {waitSearcher=true&openSearcher=false&commit=true&commit_end_point
>>> =true&wt=javabin&softCommit=false&version=2} {commit=} 0 12
>>>> [junit4:junit4]   2> 12408 T2743 C173 P38364
>> oash.ReplicationHandler.inform
>>> Commits will be reserved for  10000
>>>> [junit4:junit4]   2> 12408 T2743 C173 P38364 oash.SnapPuller.<init>  No
>>> value set for 'pollInterval'. Timer Task not started.
>>>> [junit4:junit4]   2> 12411 T2719 C175 P32591
>> oash.ReplicationHandler.inform
>>> Commits will be reserved for  10000
>>>> [junit4:junit4]   2> 12411 T2719 C175 P32591 REQ /replication
>>> {command=indexversion&wt=javabin&qt=/replication&version=2}
>> status=0
>>> QTime=2
>>>> [junit4:junit4]   2> 12412 T2743 C173 P38364
>>> oash.SnapPuller.fetchLatestIndex Master's generation: 2
>>>> [junit4:junit4]   2> 12412 T2743 C173 P38364
>>> oash.SnapPuller.fetchLatestIndex Slave's generation: 1
>>>> [junit4:junit4]   2> 12412 T2743 C173 P38364
>>> oash.SnapPuller.fetchLatestIndex Starting replication process
>>>> [junit4:junit4]   2> 12415 T2719 C175 P32591
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1
>>>> [junit4:junit4]   2> 12416 T2719 C175 P32591
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1/index
>>>> [junit4:junit4]   2> 12416 T2719 C175 P32591 REQ /replication
>>> {command=filelist&generation=2&wt=javabin&qt=/replication&version=2}
>>> status=0 QTime=1
>>>> [junit4:junit4]   2> 12417 T2743 C173 P38364
>>> oash.SnapPuller.fetchLatestIndex Number of files in latest index in master:
>> 1
>>>> [junit4:junit4]   2> 12418 T2743 C173 P38364
>>> oasc.CachingDirectoryFactory.get return new directory for
>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/index.20130104170850076 forceNew:false
>>>> [junit4:junit4]   2> 12419 T2743 C173 P38364
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2
>>>> [junit4:junit4]   2> 12419 T2743 C173 P38364
>>> oash.SnapPuller.fetchLatestIndex Starting download to
>>> 
>> RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/us
>>> r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/index.20130104170850076
>>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@d959aa8)
>>> fullCopy=true
>>>> [junit4:junit4]   2> 12423 T2719 C175 P32591 REQ /replication
>>> 
>> {file=segments_2&command=filecontent&checksum=true&generation=2&q
>>> t=/replication&wt=filestream} status=0 QTime=0
>>>> [junit4:junit4]   2> 12424 T2743 C173 P38364
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/index
>>>> [junit4:junit4]   2> 12425 T2743 C173 P38364
>>> oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
>>>> [junit4:junit4]   2> 12425 T2743 C173 P38364
>>> oash.SnapPuller.modifyIndexProps New index installed. Updating index
>>> properties... index=index.20130104170850076
>>>> [junit4:junit4]   2> 12426 T2743 C173 P38364
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2
>>>> [junit4:junit4]   2> 12427 T2743 C173 P38364
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2
>>>> [junit4:junit4]   2> 12427 T2743 C173 P38364
>> oasc.SolrCore.getNewIndexDir
>>> New index directory detected: old=./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/index/ new=./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/index.20130104170850076
>>>> [junit4:junit4]   2> 12429 T2743 C173 P38364 oasc.SolrDeletionPolicy.onInit
>>> SolrDeletionPolicy.onInit: commits:num=1
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/index.20130104170850076
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@d959aa8),segFN
>>> =segments_2,generation=2,filenames=[segments_2]
>>>> [junit4:junit4]   2> 12430 T2743 C173 P38364
>>> oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
>>>> [junit4:junit4]   2> 12430 T2743 C173 P38364
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2
>>>> [junit4:junit4]   2> 12431 T2743 C173 P38364
>>> oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
>>>> [junit4:junit4]   2> 12431 T2743 C173 P38364
>>> oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is
>>> unused... core=collection1
>>>> [junit4:junit4]   2> 12431 T2743 C173 P38364
>>> oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter...
>>> core=collection1
>>>> [junit4:junit4]   2> 12432 T2743 C173 P38364
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/index.20130104170850076
>>>> [junit4:junit4]   2> 12432 T2743 C173 P38364
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2
>>>> [junit4:junit4]   2> 12434 T2743 C173 P38364 oasc.SolrDeletionPolicy.onInit
>>> SolrDeletionPolicy.onInit: commits:num=1
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/index.20130104170850076
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@d959aa8),segFN
>>> =segments_2,generation=2,filenames=[segments_2]
>>>> [junit4:junit4]   2> 12434 T2743 C173 P38364
>>> oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
>>>> [junit4:junit4]   2> 12435 T2743 C173 P38364
>>> oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to
>> be
>>> used.
>>>> [junit4:junit4]   2> 12435 T2743 C173 P38364
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2
>>>> [junit4:junit4]   2> 12435 T2743 C173 P38364 oass.SolrIndexSearcher.<init>
>>> Opening Searcher@18eb6238 main
>>>> [junit4:junit4]   2> 12437 T2742 oasc.SolrCore.registerSearcher
>> [collection1]
>>> Registered new searcher Searcher@18eb6238
>>> main{StandardDirectoryReader(segments_2:1:nrt)}
>>>> [junit4:junit4]   2> 12437 T2742 oasc.CachingDirectoryFactory.close
>>> Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-
>>> Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/index
>>>> [junit4:junit4]   2> 12438 T2743 C173 P38364
>>> oasu.DirectUpdateHandler2.commit start
>>> 
>> commit{,optimize=false,openSearcher=false,waitSearcher=false,expungeDe
>>> letes=false,softCommit=false}
>>>> [junit4:junit4]   2> 12440 T2743 C173 P38364
>>> oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit:
>>> commits:num=2
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/index.20130104170850076
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@d959aa8),segFN
>>> =segments_2,generation=2,filenames=[segments_2]
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/index.20130104170850076
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@d959aa8),segFN
>>> =segments_3,generation=3,filenames=[segments_3]
>>>> [junit4:junit4]   2> 12440 T2743 C173 P38364
>>> oasc.SolrDeletionPolicy.updateCommits newest commit = 3[segments_3]
>>>> [junit4:junit4]   2> 12441 T2743 C173 P38364
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2
>>>> [junit4:junit4]   2> 12441 T2743 C173 P38364
>>> oasu.DirectUpdateHandler2.commit end_commit_flush
>>>> [junit4:junit4]   2> 12441 T2743 C173 P38364
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/index.20130104170850076
>>>> [junit4:junit4]   2> 12441 T2743 C173 P38364
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty2/index
>>>> [junit4:junit4]   2> 12441 T2743 C173 P38364 oasc.RecoveryStrategy.replay
>>> No replay needed. core=collection1
>>>> [junit4:junit4]   2> 12441 T2743 C173 P38364
>>> oasc.RecoveryStrategy.doRecovery Replication Recovery was successful -
>>> registering as Active. core=collection1
>>>> [junit4:junit4]   2> 12441 T2743 C173 P38364 oasc.ZkController.publish
>>> publishing core=collection1 state=active
>>>> [junit4:junit4]   2> 12442 T2743 C173 P38364 oasc.ZkController.publish
>>> numShards not found on descriptor - reading it from system property
>>>> [junit4:junit4]   2> 12443 T2743 C173 P38364
>>> oasc.RecoveryStrategy.doRecovery Finished recovery process.
>>> core=collection1
>>>> [junit4:junit4]   2> 12481 T2773 oass.IndexSchema.readSchema Reading
>> Solr
>>> Schema
>>>> [junit4:junit4]   2> 12498 T2773 oass.IndexSchema.readSchema Schema
>>> name=test
>>>> [junit4:junit4]   2> 13092 T2773 oass.OpenExchangeRatesOrgProvider.init
>>> Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>>>> [junit4:junit4]   2> 13103 T2773 oass.IndexSchema.readSchema default
>>> search field in schema is text
>>>> [junit4:junit4]   2> 13107 T2773 oass.IndexSchema.readSchema unique
>> key
>>> field: id
>>>> [junit4:junit4]   2> 13121 T2773 oass.FileExchangeRateProvider.reload
>>> Reloading exchange rates from file currency.xml
>>>> [junit4:junit4]   2> 13126 T2773 oass.FileExchangeRateProvider.reload
>>> Reloading exchange rates from file currency.xml
>>>> [junit4:junit4]   2> 13130 T2773
>>> oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates
>> from
>>> open-exchange-rates.json
>>>> [junit4:junit4]   2> 13131 T2773
>>> oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates
>> from
>>> open-exchange-rates.json
>>>> [junit4:junit4]   2> 13133 T2773 oasc.SolrCore.<init> [collection1] Opening
>>> new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-
>> Solr-
>>> Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty4-
>>> 1357312129542/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty4/
>>>> [junit4:junit4]   2> 13133 T2773 oasc.JmxMonitoredMap.<init> JMX
>>> monitoring is enabled. Adding Solr mbeans to JMX Server:
>>> com.sun.jmx.mbeanserver.JmxMBeanServer@2089208e
>>>> [junit4:junit4]   2> 13133 T2773 oasc.SolrCore.initDirectoryFactory
>>> solr.StandardDirectoryFactory
>>>> [junit4:junit4]   2> 13134 T2773 oasc.CachingDirectoryFactory.get return
>>> new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-
>>> Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1357312117664/jetty4
>>> forceNew:false
>>>> [junit4:junit4]   2> 13135 T2773 oasc.CachingDirectoryFactory.close
>>> Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-
>>> Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1357312117664/jetty4
>>>> [junit4:junit4]   2> 13135 T2773 oasc.SolrCore.getNewIndexDir New index
>>> directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty4/index/
>>>> [junit4:junit4]   2> 13136 T2773 oasc.SolrCore.initIndex WARNING
>>> [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty4/index' doesn't exist. Creating new index...
>>>> [junit4:junit4]   2> 13137 T2773 oasc.CachingDirectoryFactory.get return
>>> new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-
>>> Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty4/index forceNew:false
>>>> [junit4:junit4]   2> 13167 T2773 oasc.SolrDeletionPolicy.onCommit
>>> SolrDeletionPolicy.onCommit: commits:num=1
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty4/index
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@5c4d3edc),segF
>>> N=segments_1,generation=1,filenames=[segments_1]
>>>> [junit4:junit4]   2> 13167 T2773 oasc.SolrDeletionPolicy.updateCommits
>>> newest commit = 1[segments_1]
>>>> [junit4:junit4]   2> 13168 T2773 oasc.CachingDirectoryFactory.close
>>> Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-
>>> Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty4/index
>>>> [junit4:junit4]   2> 13169 T2773 oasc.SolrCore.initWriters created xml:
>>> solr.XMLResponseWriter
>>>> [junit4:junit4]   2> 13171 T2773 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "dedupe"
>>>> [junit4:junit4]   2> 13171 T2773 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "dedupe-allfields"
>>>> [junit4:junit4]   2> 13172 T2773 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "stored_sig"
>>>> [junit4:junit4]   2> 13172 T2773 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "uniq-fields"
>>>> [junit4:junit4]   2> 13173 T2773 oasup.UpdateRequestProcessorChain.init
>>> inserting DistributedUpdateProcessorFactory into
>>> updateRequestProcessorChain "distrib-dup-test-chain-implicit"
>>>> [junit4:junit4]   2> 13173 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler:
>>> solr.ReplicationHandler
>>>> [junit4:junit4]   2> 13173 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created /replication:
>>> solr.ReplicationHandler
>>>> [junit4:junit4]   2> 13174 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created standard:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 13175 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created /get:
>>> solr.RealTimeGetHandler
>>>> [junit4:junit4]   2> 13175 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created dismax:
>>> solr.SearchHandler
>>>> [junit4:junit4]   2> 13176 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created mock:
>>> org.apache.solr.core.MockQuerySenderListenerReqHandler
>>>> [junit4:junit4]   2> 13176 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created /admin/:
>>> org.apache.solr.handler.admin.AdminHandlers
>>>> [junit4:junit4]   2> 13177 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created defaults:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 13177 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 13177 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created lazy:
>>> solr.StandardRequestHandler
>>>> [junit4:junit4]   2> 13178 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created /update:
>>> solr.UpdateRequestHandler
>>>> [junit4:junit4]   2> 13179 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created /terms:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 13179 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 13180 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created
>>> spellCheckCompRH_Direct:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 13180 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created
>>> spellCheckWithWordbreak:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 13181 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created
>>> spellCheckWithWordbreak_Direct:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 13181 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created
>> spellCheckCompRH1:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 13182 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created mltrh:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 13182 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created tvrh:
>>> org.apache.solr.handler.component.SearchHandler
>>>> [junit4:junit4]   2> 13183 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created /mlt:
>>> solr.MoreLikeThisHandler
>>>> [junit4:junit4]   2> 13184 T2773
>>> oasc.RequestHandlers.initHandlersFromConfig created /debug/dump:
>>> solr.DumpRequestHandler
>>>> [junit4:junit4]   2> 13196 T2773 oashl.XMLLoader.init
>>> xsltCacheLifetimeSeconds=60
>>>> [junit4:junit4]   2> 13201 T2773 oasc.SolrCore.initDeprecatedSupport
>>> WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please
>>> update your config to use the ShowFileRequestHandler.
>>>> [junit4:junit4]   2> 13202 T2773 oasc.SolrCore.initDeprecatedSupport
>>> WARNING adding ShowFileRequestHandler with hidden files:
>> [SCHEMA.XML,
>>> OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-
>>> EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-
>>> ISOLATIN1ACCENT.TXT]
>>>> [junit4:junit4]   2> 13205 T2773 oasc.CachingDirectoryFactory.close
>>> Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-
>>> Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1357312117664/jetty4
>>>> [junit4:junit4]   2> 13206 T2773 oass.SolrIndexSearcher.<init> Opening
>>> Searcher@5cbf3190 main
>>>> [junit4:junit4]   2> 13207 T2773 oasu.CommitTracker.<init> Hard
>>> AutoCommit: disabled
>>>> [junit4:junit4]   2> 13208 T2773 oasu.CommitTracker.<init> Soft
>>> AutoCommit: disabled
>>>> [junit4:junit4]   2> 13208 T2773 oashc.SpellCheckComponent.inform
>>> Initializing spell checkers
>>>> [junit4:junit4]   2> 13215 T2773 oass.DirectSolrSpellChecker.init init:
>>> 
>> {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLe
>>> ngth=3}
>>>> [junit4:junit4]   2> 13243 T2707 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 13244 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Update state
>>> numShards=1 message={
>>>> [junit4:junit4]   2>      "operation":"state",
>>>> [junit4:junit4]   2>      "numShards":"1",
>>>> [junit4:junit4]   2>      "shard":"shard1",
>>>> [junit4:junit4]   2>      "roles":null,
>>>> [junit4:junit4]   2>      "state":"recovering",
>>>> [junit4:junit4]   2>      "core":"collection1",
>>>> [junit4:junit4]   2>      "collection":"collection1",
>>>> [junit4:junit4]   2>      "node_name":"127.0.0.1:46036_jxf%2Fdb",
>>>> [junit4:junit4]   2>      "base_url":"http://127.0.0.1:46036/jxf/db"}
>>>> [junit4:junit4]   2> 13253 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Update state
>>> numShards=1 message={
>>>> [junit4:junit4]   2>      "operation":"state",
>>>> [junit4:junit4]   2>      "numShards":"1",
>>>> [junit4:junit4]   2>      "shard":"shard1",
>>>> [junit4:junit4]   2>      "roles":null,
>>>> [junit4:junit4]   2>      "state":"active",
>>>> [junit4:junit4]   2>      "core":"collection1",
>>>> [junit4:junit4]   2>      "collection":"collection1",
>>>> [junit4:junit4]   2>      "node_name":"127.0.0.1:38364_jxf%2Fdb",
>>>> [junit4:junit4]   2>      "base_url":"http://127.0.0.1:38364/jxf/db"}
>>>> [junit4:junit4]   2> 13274 T2756 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> 13274 T2706 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> 13274 T2740 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> 13274 T2725 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> 13274 T2712 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> 13274 T2772 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> 13298 T2776 oasc.SolrCore.registerSearcher
>> [collection1]
>>> Registered new searcher Searcher@5cbf3190
>>> main{StandardDirectoryReader(segments_1:1)}
>>>> [junit4:junit4]   2> 13302 T2773 oasc.ZkController.publish publishing
>>> core=collection1 state=down
>>>> [junit4:junit4]   2> 13302 T2773 oasc.ZkController.publish numShards not
>>> found on descriptor - reading it from system property
>>>> [junit4:junit4]   2> 14802 T2707 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 14803 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Update state
>>> numShards=1 message={
>>>> [junit4:junit4]   2>      "operation":"state",
>>>> [junit4:junit4]   2>      "numShards":"1",
>>>> [junit4:junit4]   2>      "shard":null,
>>>> [junit4:junit4]   2>      "roles":null,
>>>> [junit4:junit4]   2>      "state":"down",
>>>> [junit4:junit4]   2>      "core":"collection1",
>>>> [junit4:junit4]   2>      "collection":"collection1",
>>>> [junit4:junit4]   2>      "node_name":"127.0.0.1:20695_jxf%2Fdb",
>>>> [junit4:junit4]   2>      "base_url":"http://127.0.0.1:20695/jxf/db"}
>>>> [junit4:junit4]   2> 14803 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Collection already exists
>>> with numShards=1
>>>> [junit4:junit4]   2> 14804 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to
>>> shard shard=shard1
>>>> [junit4:junit4]   2> 14818 T2756 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> 14818 T2740 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> 14818 T2772 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> 14818 T2725 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> 14818 T2706 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> 14818 T2712 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> 15306 T2773 oasc.CoreContainer.registerCore
>> registering
>>> core: collection1
>>>> [junit4:junit4]   2> 15306 T2773 oasc.ZkController.register Register replica -
>>> core:collection1 address:http://127.0.0.1:20695/jxf/db
>> collection:collection1
>>> shard:shard1
>>>> [junit4:junit4]   2> 15309 T2773 oasc.ZkController.register We are
>>> http://127.0.0.1:20695/jxf/db/collection1/ and leader is
>>> http://127.0.0.1:32591/jxf/db/collection1/
>>>> [junit4:junit4]   2> 15309 T2773 oasc.ZkController.register No LogReplay
>>> needed for core=collection1 baseURL=http://127.0.0.1:20695/jxf/db
>>>> [junit4:junit4]   2> 15309 T2773 oasc.ZkController.checkRecovery Core
>>> needs to recover:collection1
>>>> [junit4:junit4]   2> 15309 T2773 oasu.DefaultSolrCoreState.doRecovery
>>> Running recovery - first canceling any ongoing recovery
>>>> [junit4:junit4]   2> ASYNC  NEW_CORE C176 name=collection1
>>> org.apache.solr.core.SolrCore@e602d4f
>>> url=http://127.0.0.1:20695/jxf/db/collection1
>>> node=127.0.0.1:20695_jxf%2Fdb C176_STATE=coll:collection1
>>> core:collection1 props:{shard=null, roles=null, state=down,
>> core=collection1,
>>> collection=collection1, node_name=127.0.0.1:20695_jxf%2Fdb,
>>> base_url=http://127.0.0.1:20695/jxf/db}
>>>> [junit4:junit4]   2> 15310 T2777 C176 P20695 oasc.RecoveryStrategy.run
>>> Starting recovery process.  core=collection1 recoveringAfterStartup=true
>>>> [junit4:junit4]   2> 15310 T2773 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 15311 T2777 C176 P20695
>>> oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
>>>> [junit4:junit4]   2> 15311 T2777 C176 P20695 oasc.ZkController.publish
>>> publishing core=collection1 state=recovering
>>>> [junit4:junit4]   2> 15311 T2777 C176 P20695 oasc.ZkController.publish
>>> numShards not found on descriptor - reading it from system property
>>>> [junit4:junit4]   2> 15313 T2777 C176 P20695
>>> oascsi.HttpClientUtil.createClient Creating new http client,
>>> 
>> config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=
>>> false
>>>> [junit4:junit4]   2> 15312 T2684 oass.SolrDispatchFilter.init
>>> user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1
>>>> [junit4:junit4]   2> 15313 T2684 oass.SolrDispatchFilter.init
>>> SolrDispatchFilter.init() done
>>>> [junit4:junit4]   2> 15314 T2684 oascsi.HttpClientUtil.createClient Creating
>>> new http client,
>>> 
>> config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=
>>> false
>>>> [junit4:junit4]   2> 15329 T2684 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 15330 T2684
>>> oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for
>>> recoveries to finish - wait 15 for each attempt
>>>> [junit4:junit4]   2> 15330 T2684
>>> oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for
>>> recoveries to finish - collection: collection1 failOnTimeout:true timeout
>>> (sec):15
>>>> [junit4:junit4]   2> 15331 T2684 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2>  C174_STATE=coll:collection1 core:collection1
>>> props:{shard=shard1, roles=null, state=recovering, core=collection1,
>>> collection=collection1, node_name=127.0.0.1:46036_jxf%2Fdb,
>>> base_url=http://127.0.0.1:46036/jxf/db}
>>>> [junit4:junit4]   2> 15886 T2759 C174 P46036
>>> oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from
>>> http://127.0.0.1:32591/jxf/db/collection1/ core=collection1 -
>>> recoveringAfterStartup=true
>>>> [junit4:junit4]   2> 15886 T2759 C174 P46036 oasu.PeerSync.sync
>> PeerSync:
>>> core=collection1 url=http://127.0.0.1:46036/jxf/db START
>>> replicas=[http://127.0.0.1:32591/jxf/db/collection1/] nUpdates=100
>>>> [junit4:junit4]   2> 15886 T2759 C174 P46036 oasu.PeerSync.sync
>> WARNING
>>> no frame of reference to tell of we've missed updates
>>>> [junit4:junit4]   2> 15887 T2759 C174 P46036
>>> oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful
>> -
>>> trying replication. core=collection1
>>>> [junit4:junit4]   2> 15887 T2759 C174 P46036
>>> oasc.RecoveryStrategy.doRecovery Starting Replication Recovery.
>>> core=collection1
>>>> [junit4:junit4]   2> 15887 T2759 C174 P46036
>>> oasc.RecoveryStrategy.doRecovery Begin buffering updates.
>>> core=collection1
>>>> [junit4:junit4]   2> 15887 T2759 C174 P46036
>>> oasu.UpdateLog.bufferUpdates Starting to buffer updates.
>>> FSUpdateLog{state=ACTIVE, tlog=null}
>>>> [junit4:junit4]   2> 15887 T2759 C174 P46036
>>> oasc.RecoveryStrategy.replicate Attempting to replicate from
>>> http://127.0.0.1:32591/jxf/db/collection1/. core=collection1
>>>> [junit4:junit4]   2> 15887 T2759 C174 P46036
>>> oascsi.HttpClientUtil.createClient Creating new http client,
>>> 
>> config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=
>>> false
>>>> [junit4:junit4]   2> 15889 T2717 C175 P32591 REQ /get
>>> {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0
>>> QTime=0
>>>> [junit4:junit4]   2> 15895 T2721 C175 P32591
>>> oasu.DirectUpdateHandler2.commit start
>>> 
>> commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDel
>>> etes=false,softCommit=false}
>>>> [junit4:junit4]   2> 15936 T2721 C175 P32591
>>> oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit:
>>> commits:num=2
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1/index
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@7556f92c),segFN
>>> =segments_2,generation=2,filenames=[segments_2]
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1/index
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@7556f92c),segFN
>>> =segments_3,generation=3,filenames=[segments_3]
>>>> [junit4:junit4]   2> 15937 T2721 C175 P32591
>>> oasc.SolrDeletionPolicy.updateCommits newest commit = 3[segments_3]
>>>> [junit4:junit4]   2> 15938 T2721 C175 P32591
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1
>>>> [junit4:junit4]   2> 15938 T2721 C175 P32591
>>> oasu.DirectUpdateHandler2.commit end_commit_flush
>>>> [junit4:junit4]   2> 15939 T2721 C175 P32591 /update
>>> 
>> {waitSearcher=true&openSearcher=false&commit=true&commit_end_point
>>> =true&wt=javabin&softCommit=false&version=2} {commit=} 0 44
>>>> [junit4:junit4]   2> 15940 T2759 C174 P46036
>> oash.ReplicationHandler.inform
>>> Commits will be reserved for  10000
>>>> [junit4:junit4]   2> 15940 T2759 C174 P46036 oash.SnapPuller.<init>  No
>>> value set for 'pollInterval'. Timer Task not started.
>>>> [junit4:junit4]   2> 15942 T2719 C175 P32591 REQ /replication
>>> {command=indexversion&wt=javabin&qt=/replication&version=2}
>> status=0
>>> QTime=0
>>>> [junit4:junit4]   2> 15943 T2759 C174 P46036
>>> oash.SnapPuller.fetchLatestIndex Master's generation: 3
>>>> [junit4:junit4]   2> 15943 T2759 C174 P46036
>>> oash.SnapPuller.fetchLatestIndex Slave's generation: 1
>>>> [junit4:junit4]   2> 15943 T2759 C174 P46036
>>> oash.SnapPuller.fetchLatestIndex Starting replication process
>>>> [junit4:junit4]   2> 15945 T2719 C175 P32591
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1
>>>> [junit4:junit4]   2> 15946 T2719 C175 P32591
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1/index
>>>> [junit4:junit4]   2> 15946 T2719 C175 P32591 REQ /replication
>>> {command=filelist&generation=3&wt=javabin&qt=/replication&version=2}
>>> status=0 QTime=1
>>>> [junit4:junit4]   2> 15947 T2759 C174 P46036
>>> oash.SnapPuller.fetchLatestIndex Number of files in latest index in master:
>> 1
>>>> [junit4:junit4]   2> 15948 T2759 C174 P46036
>>> oasc.CachingDirectoryFactory.get return new directory for
>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/index.20130104170853606 forceNew:false
>>>> [junit4:junit4]   2> 15949 T2759 C174 P46036
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3
>>>> [junit4:junit4]   2> 15949 T2759 C174 P46036
>>> oash.SnapPuller.fetchLatestIndex Starting download to
>>> 
>> RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/us
>>> r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/index.20130104170853606
>>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@712a2534)
>>> fullCopy=true
>>>> [junit4:junit4]   2> 15953 T2719 C175 P32591 REQ /replication
>>> 
>> {file=segments_3&command=filecontent&checksum=true&generation=3&q
>>> t=/replication&wt=filestream} status=0 QTime=0
>>>> [junit4:junit4]   2> 15954 T2759 C174 P46036
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/index
>>>> [junit4:junit4]   2> 15954 T2759 C174 P46036
>>> oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
>>>> [junit4:junit4]   2> 15955 T2759 C174 P46036
>>> oash.SnapPuller.modifyIndexProps New index installed. Updating index
>>> properties... index=index.20130104170853606
>>>> [junit4:junit4]   2> 15956 T2759 C174 P46036
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3
>>>> [junit4:junit4]   2> 15956 T2759 C174 P46036
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3
>>>> [junit4:junit4]   2> 15957 T2759 C174 P46036
>> oasc.SolrCore.getNewIndexDir
>>> New index directory detected: old=./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/index/ new=./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/index.20130104170853606
>>>> [junit4:junit4]   2> 15959 T2759 C174 P46036 oasc.SolrDeletionPolicy.onInit
>>> SolrDeletionPolicy.onInit: commits:num=1
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/index.20130104170853606
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@712a2534),segF
>>> N=segments_3,generation=3,filenames=[segments_3]
>>>> [junit4:junit4]   2> 15960 T2759 C174 P46036
>>> oasc.SolrDeletionPolicy.updateCommits newest commit = 3[segments_3]
>>>> [junit4:junit4]   2> 15960 T2759 C174 P46036
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3
>>>> [junit4:junit4]   2> 15961 T2759 C174 P46036
>>> oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
>>>> [junit4:junit4]   2> 15961 T2759 C174 P46036
>>> oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is
>>> unused... core=collection1
>>>> [junit4:junit4]   2> 15961 T2759 C174 P46036
>>> oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter...
>>> core=collection1
>>>> [junit4:junit4]   2> 15961 T2759 C174 P46036
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/index.20130104170853606
>>>> [junit4:junit4]   2> 15962 T2759 C174 P46036
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3
>>>> [junit4:junit4]   2> 15964 T2759 C174 P46036 oasc.SolrDeletionPolicy.onInit
>>> SolrDeletionPolicy.onInit: commits:num=1
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/index.20130104170853606
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@712a2534),segF
>>> N=segments_3,generation=3,filenames=[segments_3]
>>>> [junit4:junit4]   2> 15964 T2759 C174 P46036
>>> oasc.SolrDeletionPolicy.updateCommits newest commit = 3[segments_3]
>>>> [junit4:junit4]   2> 15965 T2759 C174 P46036
>>> oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to
>> be
>>> used.
>>>> [junit4:junit4]   2> 15965 T2759 C174 P46036
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3
>>>> [junit4:junit4]   2> 15965 T2759 C174 P46036 oass.SolrIndexSearcher.<init>
>>> Opening Searcher@433d688b main
>>>> [junit4:junit4]   2> 15967 T2758 oasc.SolrCore.registerSearcher
>> [collection1]
>>> Registered new searcher Searcher@433d688b
>>> main{StandardDirectoryReader(segments_3:1:nrt)}
>>>> [junit4:junit4]   2> 15967 T2758 oasc.CachingDirectoryFactory.close
>>> Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-
>>> Solr-Tests-4.x-java7/solr/build/solr-
>>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/index
>>>> [junit4:junit4]   2> 15968 T2759 C174 P46036
>>> oasu.DirectUpdateHandler2.commit start
>>> 
>> commit{,optimize=false,openSearcher=false,waitSearcher=false,expungeDe
>>> letes=false,softCommit=false}
>>>> [junit4:junit4]   2> 15978 T2759 C174 P46036
>>> oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit:
>>> commits:num=2
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/index.20130104170853606
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@712a2534),segF
>>> N=segments_3,generation=3,filenames=[segments_3]
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/index.20130104170853606
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@712a2534),segF
>>> N=segments_4,generation=4,filenames=[segments_4]
>>>> [junit4:junit4]   2> 15979 T2759 C174 P46036
>>> oasc.SolrDeletionPolicy.updateCommits newest commit = 4[segments_4]
>>>> [junit4:junit4]   2> 15979 T2759 C174 P46036
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3
>>>> [junit4:junit4]   2> 15979 T2759 C174 P46036
>>> oasu.DirectUpdateHandler2.commit end_commit_flush
>>>> [junit4:junit4]   2> 15980 T2759 C174 P46036
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/index.20130104170853606
>>>> [junit4:junit4]   2> 15980 T2759 C174 P46036
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty3/index
>>>> [junit4:junit4]   2> 15980 T2759 C174 P46036 oasc.RecoveryStrategy.replay
>>> No replay needed. core=collection1
>>>> [junit4:junit4]   2> 15980 T2759 C174 P46036
>>> oasc.RecoveryStrategy.doRecovery Replication Recovery was successful -
>>> registering as Active. core=collection1
>>>> [junit4:junit4]   2> 15980 T2759 C174 P46036 oasc.ZkController.publish
>>> publishing core=collection1 state=active
>>>> [junit4:junit4]   2> 15980 T2759 C174 P46036 oasc.ZkController.publish
>>> numShards not found on descriptor - reading it from system property
>>>> [junit4:junit4]   2> 15982 T2759 C174 P46036
>>> oasc.RecoveryStrategy.doRecovery Finished recovery process.
>>> core=collection1
>>>> [junit4:junit4]   2> 16323 T2707 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 16324 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Update state
>>> numShards=1 message={
>>>> [junit4:junit4]   2>      "operation":"state",
>>>> [junit4:junit4]   2>      "numShards":"1",
>>>> [junit4:junit4]   2>      "shard":"shard1",
>>>> [junit4:junit4]   2>      "roles":null,
>>>> [junit4:junit4]   2>      "state":"recovering",
>>>> [junit4:junit4]   2>      "core":"collection1",
>>>> [junit4:junit4]   2>      "collection":"collection1",
>>>> [junit4:junit4]   2>      "node_name":"127.0.0.1:20695_jxf%2Fdb",
>>>> [junit4:junit4]   2>      "base_url":"http://127.0.0.1:20695/jxf/db"}
>>>> [junit4:junit4]   2> 16328 T2707
>>> oasc.Overseer$ClusterStateUpdater.updateState Update state
>>> numShards=1 message={
>>>> [junit4:junit4]   2>      "operation":"state",
>>>> [junit4:junit4]   2>      "numShards":"1",
>>>> [junit4:junit4]   2>      "shard":"shard1",
>>>> [junit4:junit4]   2>      "roles":null,
>>>> [junit4:junit4]   2>      "state":"active",
>>>> [junit4:junit4]   2>      "core":"collection1",
>>>> [junit4:junit4]   2>      "collection":"collection1",
>>>> [junit4:junit4]   2>      "node_name":"127.0.0.1:46036_jxf%2Fdb",
>>>> [junit4:junit4]   2>      "base_url":"http://127.0.0.1:46036/jxf/db"}
>>>> [junit4:junit4]   2> 16339 T2684 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 16347 T2712 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> 16347 T2756 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> 16347 T2706 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> 16347 T2772 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> 16347 T2725 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> 16347 T2740 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> 17341 T2684 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 18343 T2684 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2>  C176_STATE=coll:collection1 core:collection1
>>> props:{shard=shard1, roles=null, state=recovering, core=collection1,
>>> collection=collection1, node_name=127.0.0.1:20695_jxf%2Fdb,
>>> base_url=http://127.0.0.1:20695/jxf/db}
>>>> [junit4:junit4]   2> 19332 T2777 C176 P20695
>>> oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from
>>> http://127.0.0.1:32591/jxf/db/collection1/ core=collection1 -
>>> recoveringAfterStartup=true
>>>> [junit4:junit4]   2> 19332 T2777 C176 P20695 oasu.PeerSync.sync
>> PeerSync:
>>> core=collection1 url=http://127.0.0.1:20695/jxf/db START
>>> replicas=[http://127.0.0.1:32591/jxf/db/collection1/] nUpdates=100
>>>> [junit4:junit4]   2> 19333 T2777 C176 P20695 oasu.PeerSync.sync
>> WARNING
>>> no frame of reference to tell of we've missed updates
>>>> [junit4:junit4]   2> 19333 T2777 C176 P20695
>>> oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful
>> -
>>> trying replication. core=collection1
>>>> [junit4:junit4]   2> 19333 T2777 C176 P20695
>>> oasc.RecoveryStrategy.doRecovery Starting Replication Recovery.
>>> core=collection1
>>>> [junit4:junit4]   2> 19333 T2777 C176 P20695
>>> oasc.RecoveryStrategy.doRecovery Begin buffering updates.
>>> core=collection1
>>>> [junit4:junit4]   2> 19333 T2777 C176 P20695
>>> oasu.UpdateLog.bufferUpdates Starting to buffer updates.
>>> FSUpdateLog{state=ACTIVE, tlog=null}
>>>> [junit4:junit4]   2> 19333 T2777 C176 P20695
>>> oasc.RecoveryStrategy.replicate Attempting to replicate from
>>> http://127.0.0.1:32591/jxf/db/collection1/. core=collection1
>>>> [junit4:junit4]   2> 19333 T2777 C176 P20695
>>> oascsi.HttpClientUtil.createClient Creating new http client,
>>> 
>> config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=
>>> false
>>>> [junit4:junit4]   2> 19335 T2717 C175 P32591 REQ /get
>>> {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0
>>> QTime=0
>>>> [junit4:junit4]   2> 19344 T2715 C175 P32591
>>> oasu.DirectUpdateHandler2.commit start
>>> 
>> commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDel
>>> etes=false,softCommit=false}
>>>> [junit4:junit4]   2> 19345 T2684 oascc.ZkStateReader.updateClusterState
>>> Updating cloud state from ZooKeeper...
>>>> [junit4:junit4]   2> 19347 T2715 C175 P32591
>>> oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit:
>>> commits:num=3
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1/index
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@7556f92c),segFN
>>> =segments_2,generation=2,filenames=[segments_2]
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1/index
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@7556f92c),segFN
>>> =segments_3,generation=3,filenames=[segments_3]
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1/index
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@7556f92c),segFN
>>> =segments_4,generation=4,filenames=[segments_4]
>>>> [junit4:junit4]   2> 19347 T2715 C175 P32591
>>> oasc.SolrDeletionPolicy.updateCommits newest commit = 4[segments_4]
>>>> [junit4:junit4]   2> 19348 T2715 C175 P32591
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1
>>>> [junit4:junit4]   2> 19348 T2715 C175 P32591
>>> oasu.DirectUpdateHandler2.commit end_commit_flush
>>>> [junit4:junit4]   2> 19348 T2715 C175 P32591 /update
>>> 
>> {waitSearcher=true&openSearcher=false&commit=true&commit_end_point
>>> =true&wt=javabin&softCommit=false&version=2} {commit=} 0 4
>>>> [junit4:junit4]   2> 19349 T2777 C176 P20695
>> oash.ReplicationHandler.inform
>>> Commits will be reserved for  10000
>>>> [junit4:junit4]   2> 19349 T2777 C176 P20695 oash.SnapPuller.<init>  No
>>> value set for 'pollInterval'. Timer Task not started.
>>>> [junit4:junit4]   2> 19351 T2719 C175 P32591 REQ /replication
>>> {command=indexversion&wt=javabin&qt=/replication&version=2}
>> status=0
>>> QTime=0
>>>> [junit4:junit4]   2> 19352 T2777 C176 P20695
>>> oash.SnapPuller.fetchLatestIndex Master's generation: 4
>>>> [junit4:junit4]   2> 19352 T2777 C176 P20695
>>> oash.SnapPuller.fetchLatestIndex Slave's generation: 1
>>>> [junit4:junit4]   2> 19352 T2777 C176 P20695
>>> oash.SnapPuller.fetchLatestIndex Starting replication process
>>>> [junit4:junit4]   2> 19355 T2719 C175 P32591
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1
>>>> [junit4:junit4]   2> 19356 T2719 C175 P32591
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty1/index
>>>> [junit4:junit4]   2> 19356 T2719 C175 P32591 REQ /replication
>>> {command=filelist&generation=4&wt=javabin&qt=/replication&version=2}
>>> status=0 QTime=1
>>>> [junit4:junit4]   2> 19357 T2777 C176 P20695
>>> oash.SnapPuller.fetchLatestIndex Number of files in latest index in master:
>> 1
>>>> [junit4:junit4]   2> 19359 T2777 C176 P20695
>>> oasc.CachingDirectoryFactory.get return new directory for
>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty4/index.20130104170857016 forceNew:false
>>>> [junit4:junit4]   2> 19359 T2777 C176 P20695
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty4
>>>> [junit4:junit4]   2> 19360 T2777 C176 P20695
>>> oash.SnapPuller.fetchLatestIndex Starting download to
>>> 
>> RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/us
>>> r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty4/index.20130104170857016
>>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@1343fb44)
>>> fullCopy=true
>>>> [junit4:junit4]   2> 19363 T2719 C175 P32591 REQ /replication
>>> 
>> {file=segments_4&command=filecontent&checksum=true&generation=4&q
>>> t=/replication&wt=filestream} status=0 QTime=0
>>>> [junit4:junit4]   2> 19364 T2777 C176 P20695
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty4/index
>>>> [junit4:junit4]   2> 19365 T2777 C176 P20695
>>> oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
>>>> [junit4:junit4]   2> 19365 T2777 C176 P20695
>>> oash.SnapPuller.modifyIndexProps New index installed. Updating index
>>> properties... index=index.20130104170857016
>>>> [junit4:junit4]   2> 19366 T2777 C176 P20695
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty4
>>>> [junit4:junit4]   2> 19366 T2777 C176 P20695
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty4
>>>> [junit4:junit4]   2> 19367 T2777 C176 P20695
>> oasc.SolrCore.getNewIndexDir
>>> New index directory detected: old=./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty4/index/ new=./org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty4/index.20130104170857016
>>>> [junit4:junit4]   2> 19369 T2777 C176 P20695 oasc.SolrDeletionPolicy.onInit
>>> SolrDeletionPolicy.onInit: commits:num=1
>>>> [junit4:junit4]   2>
>>> 
>> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDi
>>> rectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-
>>> 1357312117664/jetty4/index.20130104170857016
>>> 
>> lockFactory=org.apache.lucene.store.NativeFSLockFactory@1343fb44),segF
>>> N=segments_4,generation=4,filenames=[segments_4]
>>>> [junit4:junit4]   2> 19369 T2777 C176 P20695
>>> oasc.SolrDeletionPolicy.updateCommits newest commit = 4[segments_4]
>>>> [junit4:junit4]   2> 19370 T2777 C176 P20695
>>> oasc.CachingDirectoryFactory.close Releasing
>>> directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-
>>> 4.x-java7/solr/build/solr-
>> core/test/J1/./org.apache.solr.cloud.SyncSliceTest-
>>> 1357
>>>> 
>>>> [...truncated too long message...]
>>>> 
>>>> istent
>>>> [junit4:junit4]    >    at
>>> 
>> __randomizedtesting.SeedInfo.seed([AFD4F4538756AB5B:2E327A4BF009CB6
>>> 7]:0)
>>>> [junit4:junit4]    >    at org.junit.Assert.fail(Assert.java:93)
>>>> [junit4:junit4]    >    at org.junit.Assert.assertTrue(Assert.java:43)
>>>> [junit4:junit4]    >    at org.junit.Assert.assertNotNull(Assert.java:526)
>>>> [junit4:junit4]    >    at
>>> org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:214)
>>>> [junit4:junit4]    >    at
>>> 
>> org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistri
>>> butedSearchTestCase.java:794)
>>>> [junit4:junit4]    >    at
>>> sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>>>> [junit4:junit4]    >    at
>>> 
>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.j
>>> ava:57)
>>>> [junit4:junit4]    >    at
>>> 
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces
>>> sorImpl.java:43)
>>>> [junit4:junit4]    >    at java.lang.reflect.Method.invoke(Method.java:601)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomize
>>> dRunner.java:1559)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(Rando
>>> mizedRunner.java:79)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Rando
>>> mizedRunner.java:737)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Rando
>>> mizedRunner.java:773)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Rando
>>> mizedRunner.java:787)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.
>>> evaluate(SystemPropertiesRestoreRule.java:53)
>>>> [junit4:junit4]    >    at
>>> 
>> org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRule
>>> SetupTeardownChained.java:50)
>>>> [junit4:junit4]    >    at
>>> 
>> org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCa
>>> cheSanity.java:51)
>>>> [junit4:junit4]    >    at
>>> 
>> org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeA
>>> fterRule.java:46)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1
>>> .evaluate(SystemPropertiesInvariantRule.java:55)
>>>> [junit4:junit4]    >    at
>>> 
>> org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleTh
>>> readAndTestName.java:49)
>>>> [junit4:junit4]    >    at
>>> 
>> org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRule
>>> IgnoreAfterMaxFailures.java:70)
>>>> [junit4:junit4]    >    at
>>> 
>> org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure
>>> .java:48)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(Stat
>>> ementAdapter.java:36)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.
>>> run(ThreadLeakControl.java:358)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask
>>> (ThreadLeakControl.java:782)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadL
>>> eakControl.java:442)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran
>>> domizedRunner.java:746)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(Rando
>>> mizedRunner.java:648)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(Rando
>>> mizedRunner.java:682)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Rando
>>> mizedRunner.java:693)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(Stat
>>> ementAdapter.java:36)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.
>>> evaluate(SystemPropertiesRestoreRule.java:53)
>>>> [junit4:junit4]    >    at
>>> 
>> org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeA
>>> fterRule.java:46)
>>>> [junit4:junit4]    >    at
>>> 
>> org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreCl
>>> assName.java:42)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1
>>> .evaluate(SystemPropertiesInvariantRule.java:55)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMet
>>> hodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMet
>>> hodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(Stat
>>> ementAdapter.java:36)
>>>> [junit4:junit4]    >    at
>>> 
>> org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAss
>>> ertionsRequired.java:43)
>>>> [junit4:junit4]    >    at
>>> 
>> org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure
>>> .java:48)
>>>> [junit4:junit4]    >    at
>>> 
>> org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRule
>>> IgnoreAfterMaxFailures.java:70)
>>>> [junit4:junit4]    >    at
>>> 
>> org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnore
>>> TestSuites.java:55)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(Stat
>>> ementAdapter.java:36)
>>>> [junit4:junit4]    >    at
>>> 
>> com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.
>>> run(ThreadLeakControl.java:358)
>>>> [junit4:junit4]    >    at java.lang.Thread.run(Thread.java:722)
>>>> [junit4:junit4]   2> 144300 T2684 oas.SolrTestCaseJ4.deleteCore
>>> ###deleteCore
>>>> [junit4:junit4]   2> NOTE: test params are: codec=Asserting,
>>> sim=RandomSimilarityProvider(queryNorm=true,coord=no): {},
>>> locale=ar_BH, timezone=EET
>>>> [junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Oracle Corporation
>>> 1.7.0_09 (64-bit)/cpus=16,threads=2,free=224282200,total=503316480
>>>> [junit4:junit4]   2> NOTE: All tests run in this JVM: [MultiTermTest,
>>> ShardRoutingTest, SolrIndexConfigTest, FullSolrCloudDistribCmdsTest,
>>> BasicZkTest, XmlUpdateRequestHandlerTest, LukeRequestHandlerTest,
>>> StatelessScriptUpdateProcessorFactoryTest, DebugComponentTest,
>>> TestFoldingMultitermQuery, TestSolrJ, IndexSchemaRuntimeFieldTest,
>>> TestHashPartitioner, ShardRoutingCustomTest,
>>> TestReversedWildcardFilterFactory, TestCharFilters,
>>> URLClassifyProcessorTest, TestRTGBase, TestTrie, TestSolrCoreProperties,
>>> TestPropInjectDefaults, SoftAutoCommitTest, LeaderElectionTest,
>>> TestUpdate, TestDFRSimilarityFactory, TestRemoteStreaming,
>>> TestCollationKeyRangeQueries, ConvertedLegacyTest,
>>> SignatureUpdateProcessorFactoryTest, TestPropInject,
>>> TestReplicationHandler, QueryEqualityTest, UpdateParamsTest,
>>> TestArbitraryIndexDir, BasicDistributedZk2Test,
>>> SchemaVersionSpecificBehaviorTest, TestWriterPerf, TestRealTimeGet,
>>> DocumentBuilderTest, ClusterStateTest, XsltUpdateRequestHandlerTest,
>>> TestSort, SolrCoreTest, PolyFieldTest, TestSolrDeletionPolicy1,
>>> SolrInfoMBeanTest, TestSolrDeletionPolicy2, SuggesterTest, TestDocSet,
>>> PeerSyncTest, RecoveryZkTest, TestDistributedGrouping,
>> TimeZoneUtilsTest,
>>> TestQueryUtils, TestLRUCache, TestSolrXMLSerializer,
>>> TestMergePolicyConfig, TestQuerySenderListener, ReturnFieldsTest,
>>> TestOmitPositions, PathHierarchyTokenizerFactoryTest,
>>> TestRandomFaceting, TestJoin, FileBasedSpellCheckerTest,
>>> QueryElevationComponentTest, SortByFunctionTest,
>> BasicFunctionalityTest,
>>> TestBinaryResponseWriter, TestJmxIntegration, SampleTest,
>> HighlighterTest,
>>> TestIndexSearcher, TestFunctionQuery, CacheHeaderTest,
>>> TestWordDelimiterFilterFactory, TestCSVLoader, TestCSVResponseWriter,
>>> MBeansHandlerTest, DistributedQueryElevationComponentTest,
>>> DisMaxRequestHandlerTest, IndexSchemaTest,
>>> BinaryUpdateRequestHandlerTest, QueryParsingTest,
>>> StandardRequestHandlerTest, PingRequestHandlerTest,
>>> TermVectorComponentTest, TestSurroundQueryParser,
>>> DocumentAnalysisRequestHandlerTest,
>> DirectUpdateHandlerOptimizeTest,
>>> TestSolrQueryParser, SolrPluginUtilsTest, TestValueSourceCache,
>>> RequiredFieldsTest, SuggesterFSTTest, LoggingHandlerTest,
>>> SuggesterTSTTest, UniqFieldsUpdateProcessorFactoryTest,
>>> CSVRequestHandlerTest, ShowFileRequestHandlerTest, TestSearchPerf,
>>> BadIndexSchemaTest, PrimitiveFieldTypeTest, AlternateDirectoryTest,
>>> FieldMutatingUpdateProcessorTest, TestBinaryField, SOLR749Test,
>>> TestXIncludeConfig, TestQuerySenderNoQuery, IndexReaderFactoryTest,
>>> OutputWriterTest, TestJmxMonitoredMap, EchoParamsTest,
>>> SpellPossibilityIteratorTest, TestBM25SimilarityFactory,
>>> TestPhraseSuggestions, TestPerFieldSimilarity, TestPluginEnable,
>>> LegacyHTMLStripCharFilterTest, TestLMJelinekMercerSimilarityFactory,
>>> TestCodecSupport, TestDefaultSimilarityFactory, PluginInfoTest,
>>> PrimUtilsTest, OpenExchangeRatesOrgProviderTest, ResourceLoaderTest,
>>> FileUtilsTest, DateFieldTest, SpellingQueryConverterTest, TestBadConfig,
>>> DOMUtilTest, ChaosMonkeySafeLeaderTest, UUIDFieldTest,
>>> RAMDirectoryFactoryTest, SystemInfoHandlerTest, TestUtils,
>>> ZkNodePropsTest, CircularListTest, TestDocumentBuilder,
>>> CollectionsAPIDistributedZkTest, SyncSliceTest]
>>>> [junit4:junit4] Completed on J1 in 144.33s, 1 test, 1 failure <<< FAILURES!
>>>> 
>>>> [...truncated 75 lines...]
>>>> BUILD FAILED
>>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/build.xml:353: The following error occurred while executing this line:
>>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/build.xml:39: The following error occurred while executing this line:
>>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/build.xml:178: The following error occurred while executing this
>>> line:
>>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/solr/common-build.xml:428: The following error occurred while
>>> executing this line:
>>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/lucene/common-build.xml:1176: The following error occurred while
>>> executing this line:
>>>> /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-
>>> java7/lucene/common-build.xml:841: There were test failures: 246 suites,
>>> 1020 tests, 1 failure, 23 ignored (5 assumptions)
>>>> 
>>>> Total time: 45 minutes 28 seconds
>>>> Build step 'Invoke Ant' marked build as failure
>>>> Archiving artifacts
>>>> Recording test results
>>>> Email was triggered for: Failure
>>>> Sending email for trigger: Failure
>>>> 
>>>> 
>>>> 
>>>> 
>>>> ---------------------------------------------------------------------
>>>> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
>>>> For additional commands, e-mail: dev-help@lucene.apache.org
>>> 
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
>>> For additional commands, e-mail: dev-help@lucene.apache.org
>> 
>> 
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
>> For additional commands, e-mail: dev-help@lucene.apache.org
> 
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
> 


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org


Mime
View raw message