lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-tests-only-trunk-java7 - Build # 3016 - Failure
Date Sat, 04 Aug 2012 23:00:26 GMT
Build: https://builds.apache.org/job/Lucene-Solr-tests-only-trunk-java7/3016/

1 tests failed.
REGRESSION:  org.apache.solr.cloud.SyncSliceTest.testDistribSearch

Error Message:
No live SolrServers available to handle this request

Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request
	at __randomizedtesting.SeedInfo.seed([DB32D3B448B10D0A:5AD45DAC3FEE6D36]:0)
	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:322)
	at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:237)
	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
	at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:179)
	at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:155)
	at org.apache.solr.cloud.FullSolrCloudTest.commit(FullSolrCloudTest.java:1477)
	at org.apache.solr.cloud.SyncSliceTest.waitForThingsToLevelOut(SyncSliceTest.java:268)
	at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:162)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:679)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1995)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$1100(RandomizedRunner.java:132)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:818)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:877)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:891)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:32)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleReportUncaughtExceptions$1.evaluate(TestRuleReportUncaughtExceptions.java:68)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:825)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$700(RandomizedRunner.java:132)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3$1.run(RandomizedRunner.java:671)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:697)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:736)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:747)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleReportUncaughtExceptions$1.evaluate(TestRuleReportUncaughtExceptions.java:68)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:38)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleNoInstanceHooksOverrides$1.evaluate(TestRuleNoInstanceHooksOverrides.java:53)
	at org.apache.lucene.util.TestRuleNoStaticHooksShadowing$1.evaluate(TestRuleNoStaticHooksShadowing.java:52)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:36)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSuite(RandomizedRunner.java:605)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$400(RandomizedRunner.java:132)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$2.run(RandomizedRunner.java:551)




Build Log:
[...truncated 7350 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.SyncSliceTest
[junit4:junit4] ERROR    106s J0 | SyncSliceTest.testDistribSearch
[junit4:junit4]    > Throwable #1: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([DB32D3B448B10D0A:5AD45DAC3FEE6D36]:0)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:322)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:237)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:179)
[junit4:junit4]    > 	at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:155)
[junit4:junit4]    > 	at org.apache.solr.cloud.FullSolrCloudTest.commit(FullSolrCloudTest.java:1477)
[junit4:junit4]    > 	at org.apache.solr.cloud.SyncSliceTest.waitForThingsToLevelOut(SyncSliceTest.java:268)
[junit4:junit4]    > 	at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:162)
[junit4:junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:679)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4:junit4]    > 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4:junit4]    > 	at java.lang.reflect.Method.invoke(Method.java:601)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1995)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$1100(RandomizedRunner.java:132)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:818)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:877)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:891)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:32)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleReportUncaughtExceptions$1.evaluate(TestRuleReportUncaughtExceptions.java:68)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:825)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$700(RandomizedRunner.java:132)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3$1.run(RandomizedRunner.java:671)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:697)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:736)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:747)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleReportUncaughtExceptions$1.evaluate(TestRuleReportUncaughtExceptions.java:68)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:38)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleNoInstanceHooksOverrides$1.evaluate(TestRuleNoInstanceHooksOverrides.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleNoStaticHooksShadowing$1.evaluate(TestRuleNoStaticHooksShadowing.java:52)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:36)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSuite(RandomizedRunner.java:605)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$400(RandomizedRunner.java:132)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$2.run(RandomizedRunner.java:551)
[junit4:junit4]    > 
[junit4:junit4]   2> 3 T500 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/./solrtest-SyncSliceTest-1344120495091
[junit4:junit4]   2> 4 T500 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 7 T501 oazs.ZooKeeperServer.setTickTime tickTime set to 3000
[junit4:junit4]   2> 7 T501 oazs.NIOServerCnxn$Factory.<init> binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 7 T501 oazsp.FileTxnSnapLog.save Snapshotting: 0
[junit4:junit4]   2> 105 T500 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35510 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@413c1a86
[junit4:junit4]   2> 105 T506 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:35510
[junit4:junit4]   2> 106 T506 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35510, initiating session
[junit4:junit4]   2> 106 T502 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:35511
[junit4:junit4]   2> 106 T502 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:35511
[junit4:junit4]   2> 106 T504 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 108 T504 oazs.NIOServerCnxn.finishSessionInit Established session 0x138f3d31bf70000 with negotiated timeout 10000 for client /140.211.11.196:35511
[junit4:junit4]   2> 108 T506 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:35510, sessionid = 0x138f3d31bf70000, negotiated timeout = 10000
[junit4:junit4]   2> 108 T507 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@413c1a86 name:ZooKeeperConnection Watcher:127.0.0.1:35510 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 108 T500 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 111 T505 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x138f3d31bf70000
[junit4:junit4]   2> 118 T507 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 118 T500 oaz.ZooKeeper.close Session: 0x138f3d31bf70000 closed
[junit4:junit4]   2> 119 T502 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:35511 which had sessionid 0x138f3d31bf70000
[junit4:junit4]   2> 119 T500 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35510/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@6bd5a965
[junit4:junit4]   2> 119 T508 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:35510
[junit4:junit4]   2> 120 T508 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35510, initiating session
[junit4:junit4]   2> 120 T502 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:35512
[junit4:junit4]   2> 120 T502 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:35512
[junit4:junit4]   2> 121 T504 oazs.NIOServerCnxn.finishSessionInit Established session 0x138f3d31bf70001 with negotiated timeout 10000 for client /140.211.11.196:35512
[junit4:junit4]   2> 121 T508 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:35510, sessionid = 0x138f3d31bf70001, negotiated timeout = 10000
[junit4:junit4]   2> 121 T509 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6bd5a965 name:ZooKeeperConnection Watcher:127.0.0.1:35510/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 121 T500 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 132 T500 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 134 T500 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 136 T500 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 146 T500 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 156 T500 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 259 T500 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 261 T500 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 273 T500 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 276 T500 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 283 T500 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 285 T500 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 288 T500 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 290 T500 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 298 T505 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x138f3d31bf70001
[junit4:junit4]   2> 299 T509 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 299 T500 oaz.ZooKeeper.close Session: 0x138f3d31bf70001 closed
[junit4:junit4]   2> 299 T502 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:35512 which had sessionid 0x138f3d31bf70001
[junit4:junit4]   2> 300 T500 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 302 T500 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:35513
[junit4:junit4]   2> 303 T500 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 303 T500 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 303 T500 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 315 T500 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 315 T500 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 315 T500 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 316 T500 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 316 T500 oasc.CoreContainer.<init> New CoreContainer 948223506
[junit4:junit4]   2> 316 T500 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 316 T500 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 330 T500 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 343 T500 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:35510/solr
[junit4:junit4]   2> 344 T500 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35510/solr sessionTimeout=8000 watcher=org.apache.solr.common.cloud.ConnectionManager@3a00ad7c
[junit4:junit4]   2> 345 T519 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:35510
[junit4:junit4]   2> 346 T519 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35510, initiating session
[junit4:junit4]   2> 346 T502 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:35514
[junit4:junit4]   2> 346 T502 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:35514
[junit4:junit4]   2> 347 T504 oazs.NIOServerCnxn.finishSessionInit Established session 0x138f3d31bf70002 with negotiated timeout 8000 for client /140.211.11.196:35514
[junit4:junit4]   2> 348 T519 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:35510, sessionid = 0x138f3d31bf70002, negotiated timeout = 8000
[junit4:junit4]   2> 348 T520 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a00ad7c name:ZooKeeperConnection Watcher:127.0.0.1:35510/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 349 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70002 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 350 T500 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 360 T500 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35513_solr
[junit4:junit4]   2> 361 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70002 type:delete cxid:0x7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:35513_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:35513_solr
[junit4:junit4]   2> 366 T500 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35513_solr
[junit4:junit4]   2> 369 T500 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 369 T500 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 370 T500 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 370 T500 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 370 T500 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 370 T500 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 370 T500 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 371 T500 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 381 T500 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 382 T500 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 392 T500 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 398 T500 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 413 T500 oasc.Overseer.start Overseer (id=88088280766545922-127.0.0.1:35513_solr-n_0000000000) starting
[junit4:junit4]   2> 413 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70002 type:create cxid:0x19 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 420 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70002 type:create cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 430 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70002 type:create cxid:0x1b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 431 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70002 type:create cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 432 T522 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 433 T500 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 434 T500 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 436 T521 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 440 T500 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 440 T500 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 441 T500 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 441 T500 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 442 T500 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 442 T500 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 443 T500 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 477 T500 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 534 T500 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 634 T500 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 639 T500 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1310 T500 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1317 T500 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1320 T500 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1331 T500 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1335 T500 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1338 T500 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1339 T500 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1340 T500 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1344120495090/control/data/
[junit4:junit4]   2> 1340 T500 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@669ca370
[junit4:junit4]   2> 1342 T500 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1344120495090/control/data/index/
[junit4:junit4]   2> 1343 T500 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1344120495090/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1347 T500 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/control/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@306a9eb4; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1348 T500 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 1348 T500 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 1349 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1349 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 1350 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1350 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 1351 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1351 T500 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1351 T500 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1351 T500 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1352 T500 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1352 T500 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 1352 T500 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 1353 T500 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1353 T500 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 1353 T500 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 1353 T500 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 1354 T500 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1354 T500 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1354 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1355 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1355 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1355 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1355 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1356 T500 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1356 T500 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 1356 T500 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 1357 T500 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1359 T500 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 1360 T500 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> 1363 T500 oass.SolrIndexSearcher.<init> Opening Searcher@32f0af3d main
[junit4:junit4]   2> 1363 T500 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1364 T500 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1364 T500 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 1376 T500 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 1431 T523 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@32f0af3d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1432 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70002 type:create cxid:0x52 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4]   2> 1435 T500 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 1435 T500 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:35513/solr shardId:control_shard
[junit4:junit4]   2> 1436 T500 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/control_shard/election
[junit4:junit4]   2> 1447 T521 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 1450 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70002 type:create cxid:0x6a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 1458 T500 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/control_shard
[junit4:junit4]   2> 1472 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70002 type:create cxid:0x79 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1493 T520 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 1540 T500 oasc.ZkController.register We are http://127.0.0.1:35513/solr/collection1/ and leader is http://127.0.0.1:35513/solr/collection1/
[junit4:junit4]   2> 1540 T500 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35513/solr
[junit4:junit4]   2> 1540 T500 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 1542 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 1542 T500 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0
[junit4:junit4]   2> 1542 T500 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 1543 T500 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 1552 T500 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 1554 T500 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:35516
[junit4:junit4]   2> 1555 T500 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 1555 T500 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 1555 T500 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 1566 T500 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 1566 T500 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 1566 T500 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 1567 T500 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 1567 T500 oasc.CoreContainer.<init> New CoreContainer 650296839
[junit4:junit4]   2> 1567 T500 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 1568 T500 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 1582 T500 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 1595 T500 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:35510/solr
[junit4:junit4]   2> 1595 T500 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35510/solr sessionTimeout=8000 watcher=org.apache.solr.common.cloud.ConnectionManager@2bf9490a
[junit4:junit4]   2> 1596 T533 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:35510
[junit4:junit4]   2> 1597 T533 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35510, initiating session
[junit4:junit4]   2> 1597 T502 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:35517
[junit4:junit4]   2> 1597 T502 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:35517
[junit4:junit4]   2> 1605 T504 oazs.NIOServerCnxn.finishSessionInit Established session 0x138f3d31bf70003 with negotiated timeout 8000 for client /140.211.11.196:35517
[junit4:junit4]   2> 1605 T533 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:35510, sessionid = 0x138f3d31bf70003, negotiated timeout = 8000
[junit4:junit4]   2> 1605 T534 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2bf9490a name:ZooKeeperConnection Watcher:127.0.0.1:35510/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 1606 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70003 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1617 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70003 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1624 T500 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35516_solr
[junit4:junit4]   2> 1624 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70003 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:35516_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:35516_solr
[junit4:junit4]   2> 1626 T500 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35516_solr
[junit4:junit4]   2> 1628 T520 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 1628 T500 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 1628 T500 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 1629 T500 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 1629 T500 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 1629 T500 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 1629 T500 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 1629 T500 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 1630 T500 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 1630 T500 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 1630 T500 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 1642 T500 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 1648 T500 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 1648 T500 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 1649 T500 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 1649 T500 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 1650 T500 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 1650 T500 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 1651 T500 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 1688 T500 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 1751 T500 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 1853 T500 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 1858 T500 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 2008 T521 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2015 T534 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2015 T520 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2447 T500 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 2454 T500 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 2457 T500 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 2471 T500 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2475 T500 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2478 T500 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2479 T500 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2480 T500 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty1/
[junit4:junit4]   2> 2481 T500 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@669ca370
[junit4:junit4]   2> 2481 T500 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty1/index/
[junit4:junit4]   2> 2482 T500 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 2486 T500 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty1/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1aac7c9e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 2486 T500 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 2486 T500 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 2488 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 2488 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 2488 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 2489 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 2489 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 2489 T500 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 2490 T500 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 2490 T500 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 2490 T500 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 2491 T500 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 2491 T500 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 2492 T500 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 2492 T500 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 2492 T500 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 2493 T500 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 2493 T500 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 2493 T500 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2494 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2494 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2494 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2495 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2495 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2495 T500 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2496 T500 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 2496 T500 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 2497 T500 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 2499 T500 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 2500 T500 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> 2502 T500 oass.SolrIndexSearcher.<init> Opening Searcher@27245784 main
[junit4:junit4]   2> 2503 T500 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 2503 T500 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 2503 T500 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 2508 T500 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 2548 T535 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@27245784 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 3022 T521 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3035 T520 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3035 T534 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3053 T500 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 3053 T500 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:35516/solr shardId:shard1
[junit4:junit4]   2> 3054 T500 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 3061 T500 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 3071 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70003 type:create cxid:0x4b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3539 T521 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3555 T534 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3555 T520 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3587 T500 oasc.ZkController.register We are http://127.0.0.1:35516/solr/collection1/ and leader is http://127.0.0.1:35516/solr/collection1/
[junit4:junit4]   2> 3587 T500 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35516/solr
[junit4:junit4]   2> 3588 T500 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 3590 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3591 T500 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0
[junit4:junit4]   2> 3591 T500 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 3592 T500 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 3612 T500 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 3616 T500 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:35518
[junit4:junit4]   2> 3616 T500 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3617 T500 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 3618 T500 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 3641 T500 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 3641 T500 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3642 T500 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 3642 T500 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 3643 T500 oasc.CoreContainer.<init> New CoreContainer 1648862199
[junit4:junit4]   2> 3643 T500 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 3644 T500 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 3674 T500 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 3704 T500 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:35510/solr
[junit4:junit4]   2> 3704 T500 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35510/solr sessionTimeout=8000 watcher=org.apache.solr.common.cloud.ConnectionManager@4bf29b82
[junit4:junit4]   2> 3706 T545 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:35510
[junit4:junit4]   2> 3707 T545 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35510, initiating session
[junit4:junit4]   2> 3707 T502 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:35519
[junit4:junit4]   2> 3707 T502 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:35519
[junit4:junit4]   2> 3708 T504 oazs.NIOServerCnxn.finishSessionInit Established session 0x138f3d31bf70004 with negotiated timeout 8000 for client /140.211.11.196:35519
[junit4:junit4]   2> 3708 T545 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:35510, sessionid = 0x138f3d31bf70004, negotiated timeout = 8000
[junit4:junit4]   2> 3708 T546 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4bf29b82 name:ZooKeeperConnection Watcher:127.0.0.1:35510/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3709 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70004 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3710 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70004 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3712 T500 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35518_solr
[junit4:junit4]   2> 3712 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70004 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:35518_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:35518_solr
[junit4:junit4]   2> 3713 T500 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35518_solr
[junit4:junit4]   2> 3722 T534 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 3722 T520 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 3723 T500 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 3723 T500 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 3724 T500 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 3724 T500 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 3724 T500 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 3724 T500 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 3725 T500 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 3725 T500 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 3725 T500 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 3726 T500 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 3742 T500 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3750 T500 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 3751 T500 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 3751 T500 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 3752 T500 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 3753 T500 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 3754 T500 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 3754 T500 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 3822 T500 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 3918 T500 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 4019 T500 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 4026 T500 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 4061 T521 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4109 T520 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4109 T546 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4109 T534 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4819 T500 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 4828 T500 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 4833 T500 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 4849 T500 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 4854 T500 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 4859 T500 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 4860 T500 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 4862 T500 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty2/
[junit4:junit4]   2> 4862 T500 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@669ca370
[junit4:junit4]   2> 4863 T500 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty2/index/
[junit4:junit4]   2> 4864 T500 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 4869 T500 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty2/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@10b7868f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 4870 T500 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 4870 T500 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 4872 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 4873 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 4873 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 4873 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 4874 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 4875 T500 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 4875 T500 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 4875 T500 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 4876 T500 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 4876 T500 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 4877 T500 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 4877 T500 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 4878 T500 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 4878 T500 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 4879 T500 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 4879 T500 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 4879 T500 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4880 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4880 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4881 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4881 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4882 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4882 T500 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4883 T500 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 4883 T500 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 4884 T500 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 4887 T500 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 4888 T500 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> 4891 T500 oass.SolrIndexSearcher.<init> Opening Searcher@bdc230 main
[junit4:junit4]   2> 4892 T500 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 4893 T500 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 4893 T500 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 4899 T500 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 4946 T547 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@bdc230 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 5147 T521 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5160 T546 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5160 T534 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5160 T520 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5451 T500 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 5451 T500 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:35518/solr shardId:shard1
[junit4:junit4]   2> 5455 T500 oasc.ZkController.register We are http://127.0.0.1:35518/solr/collection1/ and leader is http://127.0.0.1:35516/solr/collection1/
[junit4:junit4]   2> 5455 T500 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35518/solr
[junit4:junit4]   2> 5455 T500 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> ASYNC  NEW_CORE C41 name=collection1 org.apache.solr.core.SolrCore@14078a2d url=http://127.0.0.1:35518/solr/collection1 node=127.0.0.1:35518_solr
[junit4:junit4]   2> 5456 T548 C41 P35518 oasc.RecoveryStrategy.run Starting recovery process. recoveringAfterStartup=true
[junit4:junit4]   2> 5457 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5457 T548 C41 P35518 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 5458 T500 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0
[junit4:junit4]   2> 5458 T500 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 5458 T500 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 5469 T500 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 5471 T548 C41 P35518 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 5471 T500 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:35520
[junit4:junit4]   2> 5472 T500 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 5472 T500 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 5473 T500 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 5486 T500 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 5486 T500 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 5486 T500 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 5487 T500 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 5487 T500 oasc.CoreContainer.<init> New CoreContainer 1699526318
[junit4:junit4]   2> 5487 T500 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 5488 T500 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 5508 T500 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 5529 T500 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:35510/solr
[junit4:junit4]   2> 5529 T500 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35510/solr sessionTimeout=8000 watcher=org.apache.solr.common.cloud.ConnectionManager@1c79d3cf
[junit4:junit4]   2> 5530 T558 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:35510
[junit4:junit4]   2> 5531 T558 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35510, initiating session
[junit4:junit4]   2> 5532 T502 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:35522
[junit4:junit4]   2> 5532 T502 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:35522
[junit4:junit4]   2> 5533 T504 oazs.NIOServerCnxn.finishSessionInit Established session 0x138f3d31bf70005 with negotiated timeout 8000 for client /140.211.11.196:35522
[junit4:junit4]   2> 5533 T558 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:35510, sessionid = 0x138f3d31bf70005, negotiated timeout = 8000
[junit4:junit4]   2> 5534 T559 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c79d3cf name:ZooKeeperConnection Watcher:127.0.0.1:35510/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 5534 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70005 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5536 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70005 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5537 T500 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35520_solr
[junit4:junit4]   2> 5538 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70005 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:35520_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:35520_solr
[junit4:junit4]   2> 5546 T500 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35520_solr
[junit4:junit4]   2> 5548 T546 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 5549 T520 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 5549 T534 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 5550 T500 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 5550 T500 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 5550 T500 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 5551 T500 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 5551 T500 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 5551 T500 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 5552 T500 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 5552 T500 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 5552 T500 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 5553 T500 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 5568 T500 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 5577 T500 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 5577 T500 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 5578 T500 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 5578 T500 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 5579 T500 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 5580 T500 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 5581 T500 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 5639 T500 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 5665 T521 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5679 T546 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5679 T559 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5679 T534 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5679 T520 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5738 T500 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 5839 T500 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 5846 T500 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 6698 T500 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 6707 T500 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 6712 T500 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 6728 T500 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6734 T500 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6743 T500 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6745 T500 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6746 T500 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty3/
[junit4:junit4]   2> 6748 T500 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@669ca370
[junit4:junit4]   2> 6749 T500 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty3/index/
[junit4:junit4]   2> 6750 T500 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 6761 T500 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty3/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d1abe27; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 6761 T500 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 6762 T500 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 6764 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 6764 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 6765 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 6765 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 6766 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 6766 T500 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 6767 T500 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 6767 T500 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 6768 T500 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 6768 T500 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 6768 T500 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 6769 T500 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 6769 T500 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 6770 T500 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 6770 T500 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 6771 T500 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 6771 T500 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6771 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6772 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6778 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6779 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6779 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6780 T500 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6780 T500 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 6781 T500 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 6782 T500 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 6784 T500 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 6785 T500 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> 6789 T500 oass.SolrIndexSearcher.<init> Opening Searcher@55c8bb90 main
[junit4:junit4]   2> 6790 T500 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 6790 T500 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 6791 T500 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 6801 T500 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 6853 T560 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@55c8bb90 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 7188 T521 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7194 T546 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7194 T534 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7194 T520 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7194 T559 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7358 T500 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 7358 T500 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:35520/solr shardId:shard1
[junit4:junit4]   2> 7362 T500 oasc.ZkController.register We are http://127.0.0.1:35520/solr/collection1/ and leader is http://127.0.0.1:35516/solr/collection1/
[junit4:junit4]   2> 7362 T500 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35520/solr
[junit4:junit4]   2> 7362 T500 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> ASYNC  NEW_CORE C42 name=collection1 org.apache.solr.core.SolrCore@603641c6 url=http://127.0.0.1:35520/solr/collection1 node=127.0.0.1:35520_solr
[junit4:junit4]   2> 7364 T561 C42 P35520 oasc.RecoveryStrategy.run Starting recovery process. recoveringAfterStartup=true
[junit4:junit4]   2> 7365 T561 C42 P35520 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 7364 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7366 T561 C42 P35520 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 7366 T500 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0
[junit4:junit4]   2> 7370 T500 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 7370 T500 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 7384 T500 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 7386 T500 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:35525
[junit4:junit4]   2> 7387 T500 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 7387 T500 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 7387 T500 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 7403 T500 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 7404 T500 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 7404 T500 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 7404 T500 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 7405 T500 oasc.CoreContainer.<init> New CoreContainer 1493638406
[junit4:junit4]   2> 7405 T500 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 7405 T500 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 7426 T500 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 7523 T500 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:35510/solr
[junit4:junit4]   2> 7524 T500 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35510/solr sessionTimeout=8000 watcher=org.apache.solr.common.cloud.ConnectionManager@5fe82926
[junit4:junit4]   2> 7525 T571 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:35510
[junit4:junit4]   2> 7526 T571 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35510, initiating session
[junit4:junit4]   2> 7526 T502 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:35526
[junit4:junit4]   2> 7526 T502 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:35526
[junit4:junit4]   2> 7528 T504 oazs.NIOServerCnxn.finishSessionInit Established session 0x138f3d31bf70006 with negotiated timeout 8000 for client /140.211.11.196:35526
[junit4:junit4]   2> 7528 T571 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:35510, sessionid = 0x138f3d31bf70006, negotiated timeout = 8000
[junit4:junit4]   2> 7528 T572 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5fe82926 name:ZooKeeperConnection Watcher:127.0.0.1:35510/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 7529 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70006 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7539 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70006 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7540 T500 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35525_solr
[junit4:junit4]   2> 7541 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70006 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:35525_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:35525_solr
[junit4:junit4]   2> 7547 T500 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35525_solr
[junit4:junit4]   2> 7549 T546 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7550 T520 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7550 T534 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7550 T559 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7551 T500 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 7551 T500 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 7551 T500 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 7552 T500 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 7552 T500 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 7552 T500 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 7553 T500 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 7553 T500 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 7553 T500 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 7553 T500 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 7570 T500 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 7578 T500 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 7579 T500 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 7579 T500 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 7580 T500 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 7581 T500 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 7582 T500 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 7582 T500 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 7634 T500 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 7698 T521 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7712 T546 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7712 T534 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7712 T572 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7712 T559 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7712 T520 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7717 T500 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 7818 T500 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 7824 T500 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 8548 T500 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 8556 T500 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 8561 T500 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 8576 T500 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8581 T500 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8585 T500 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8586 T500 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8588 T500 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty4/
[junit4:junit4]   2> 8588 T500 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@669ca370
[junit4:junit4]   2> 8589 T500 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty4/index/
[junit4:junit4]   2> 8590 T500 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 8594 T500 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty4/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@543d5d50; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 8595 T500 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 8595 T500 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 8597 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 8597 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 8598 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 8598 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 8599 T500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 8599 T500 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 8599 T500 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 8600 T500 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 8600 T500 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 8601 T500 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 8601 T500 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 8602 T500 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 8602 T500 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 8602 T500 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 8603 T500 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 8603 T500 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 8604 T500 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8604 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8604 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8605 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8605 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8606 T500 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8606 T500 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8607 T500 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 8607 T500 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 8608 T500 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 8610 T500 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 8611 T500 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> 8615 T500 oass.SolrIndexSearcher.<init> Opening Searcher@3beb96d1 main
[junit4:junit4]   2> 8616 T500 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 8616 T500 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 8616 T500 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 8628 T500 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 8677 T573 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3beb96d1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 8719 T521 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8733 T546 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8733 T534 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8733 T559 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8733 T572 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8733 T520 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9181 T500 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 9181 T500 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:35525/solr shardId:shard1
[junit4:junit4]   2> 9185 T500 oasc.ZkController.register We are http://127.0.0.1:35525/solr/collection1/ and leader is http://127.0.0.1:35516/solr/collection1/
[junit4:junit4]   2> 9186 T500 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35525/solr
[junit4:junit4]   2> 9186 T500 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> ASYNC  NEW_CORE C43 name=collection1 org.apache.solr.core.SolrCore@19f00e8b url=http://127.0.0.1:35525/solr/collection1 node=127.0.0.1:35525_solr
[junit4:junit4]   2> 9187 T574 C43 P35525 oasc.RecoveryStrategy.run Starting recovery process. recoveringAfterStartup=true
[junit4:junit4]   2> 9188 T574 C43 P35525 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 9188 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9189 T574 C43 P35525 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 9189 T500 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0
[junit4:junit4]   2> 9190 T500 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 9190 T500 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 9205 T500 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35510/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@eb34679
[junit4:junit4]   2> 9206 T575 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:35510
[junit4:junit4]   2> 9207 T575 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35510, initiating session
[junit4:junit4]   2> 9207 T502 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:35528
[junit4:junit4]   2> 9207 T502 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:35528
[junit4:junit4]   2> 9209 T504 oazs.NIOServerCnxn.finishSessionInit Established session 0x138f3d31bf70007 with negotiated timeout 10000 for client /140.211.11.196:35528
[junit4:junit4]   2> 9209 T575 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:35510, sessionid = 0x138f3d31bf70007, negotiated timeout = 10000
[junit4:junit4]   2> 9209 T576 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@eb34679 name:ZooKeeperConnection Watcher:127.0.0.1:35510/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 9210 T500 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9211 T500 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:false
[junit4:junit4]   2> 9212 T500 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 9227 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9229 T500 oasc.AbstractDistributedZkTestCase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):360
[junit4:junit4]   2> 9229 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9238 T521 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9243 T546 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9243 T520 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9243 T559 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9243 T576 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9243 T572 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9243 T534 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10231 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11233 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12237 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C41_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:35518_solr, base_url=http://127.0.0.1:35518/solr}
[junit4:junit4]   2> 12495 T548 C41 P35518 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:35516/solr/collection1/ recoveringAfterStartup=true
[junit4:junit4]   2> 12496 T548 C41 P35518 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35518/solr START replicas=[http://127.0.0.1:35516/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 12497 T548 C41 P35518 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication
[junit4:junit4]   2> 12497 T548 C41 P35518 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery
[junit4:junit4]   2> 12497 T548 C41 P35518 oasc.RecoveryStrategy.doRecovery Begin buffering updates
[junit4:junit4]   2> 12497 T548 C41 P35518 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 12497 T548 C41 P35518 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:35516/solr/collection1/
[junit4:junit4]   2> 12497 T548 C41 P35518 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C44 name=collection1 org.apache.solr.core.SolrCore@287b65b8 url=http://127.0.0.1:35516/solr/collection1 node=127.0.0.1:35516_solr
[junit4:junit4]   2> 12505 T529 C44 P35516 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 12516 T530 C44 P35516 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12518 T530 C44 P35516 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty1/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1aac7c9e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 12519 T530 C44 P35516 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 12520 T530 C44 P35516 oass.SolrIndexSearcher.<init> Opening Searcher@12d82cb6 main
[junit4:junit4]   2> 12520 T530 C44 P35516 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12521 T535 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@12d82cb6 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 12521 T530 C44 P35516 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 5
[junit4:junit4]   2> 12522 T548 C41 P35518 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 12522 T548 C41 P35518 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 12524 T531 C44 P35516 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 12524 T531 C44 P35516 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12526 T548 C41 P35518 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty2/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@10b7868f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 12527 T548 C41 P35518 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 12527 T548 C41 P35518 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12556 T548 C41 P35518 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty2/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@10b7868f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty2/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@10b7868f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 12556 T548 C41 P35518 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 12558 T548 C41 P35518 oass.SolrIndexSearcher.<init> Opening Searcher@73a3a121 main
[junit4:junit4]   2> 12558 T548 C41 P35518 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12559 T547 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@73a3a121 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 12559 T548 C41 P35518 oasc.RecoveryStrategy.replay No replay needed
[junit4:junit4]   2> 12559 T548 C41 P35518 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active
[junit4:junit4]   2> 12561 T548 C41 P35518 oasc.RecoveryStrategy.doRecovery Finished recovery process
[junit4:junit4]   2> 12769 T521 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12783 T546 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12783 T576 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12783 T534 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12783 T572 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12783 T559 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12783 T520 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 13239 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14241 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C42_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:35520_solr, base_url=http://127.0.0.1:35520/solr}
[junit4:junit4]   2> 14383 T561 C42 P35520 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:35516/solr/collection1/ recoveringAfterStartup=true
[junit4:junit4]   2> 14384 T561 C42 P35520 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35520/solr START replicas=[http://127.0.0.1:35516/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 14384 T561 C42 P35520 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication
[junit4:junit4]   2> 14384 T561 C42 P35520 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery
[junit4:junit4]   2> 14384 T561 C42 P35520 oasc.RecoveryStrategy.doRecovery Begin buffering updates
[junit4:junit4]   2> 14384 T561 C42 P35520 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 14384 T561 C42 P35520 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:35516/solr/collection1/
[junit4:junit4]   2> 14384 T561 C42 P35520 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 14387 T529 C44 P35516 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 14393 T532 C44 P35516 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 14396 T532 C44 P35516 oass.SolrIndexSearcher.<init> Opening Searcher@5726f91e main
[junit4:junit4]   2> 14396 T532 C44 P35516 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 14397 T535 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5726f91e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 14397 T532 C44 P35516 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 4
[junit4:junit4]   2> 14398 T561 C42 P35520 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 14398 T561 C42 P35520 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 14400 T531 C44 P35516 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   2> 14402 T561 C42 P35520 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty3/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d1abe27; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 14403 T561 C42 P35520 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 14403 T561 C42 P35520 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 14406 T561 C42 P35520 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty3/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d1abe27; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty3/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d1abe27; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 14406 T561 C42 P35520 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 14408 T561 C42 P35520 oass.SolrIndexSearcher.<init> Opening Searcher@36413532 main
[junit4:junit4]   2> 14408 T561 C42 P35520 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 14409 T560 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@36413532 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 14409 T561 C42 P35520 oasc.RecoveryStrategy.replay No replay needed
[junit4:junit4]   2> 14409 T561 C42 P35520 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active
[junit4:junit4]   2> 14411 T561 C42 P35520 oasc.RecoveryStrategy.doRecovery Finished recovery process
[junit4:junit4]   2> 14793 T521 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14811 T576 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14811 T546 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14811 T534 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14811 T572 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14811 T520 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14811 T559 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15243 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C43_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:35525_solr, base_url=http://127.0.0.1:35525/solr}
[junit4:junit4]   2> 16208 T574 C43 P35525 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:35516/solr/collection1/ recoveringAfterStartup=true
[junit4:junit4]   2> 16209 T574 C43 P35525 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35525/solr START replicas=[http://127.0.0.1:35516/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 16209 T574 C43 P35525 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication
[junit4:junit4]   2> 16209 T574 C43 P35525 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery
[junit4:junit4]   2> 16210 T574 C43 P35525 oasc.RecoveryStrategy.doRecovery Begin buffering updates
[junit4:junit4]   2> 16210 T574 C43 P35525 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 16210 T574 C43 P35525 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:35516/solr/collection1/
[junit4:junit4]   2> 16210 T574 C43 P35525 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 16213 T529 C44 P35516 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=0 
[junit4:junit4]   2> 16222 T526 C44 P35516 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16224 T526 C44 P35516 oass.SolrIndexSearcher.<init> Opening Searcher@2767cff0 main
[junit4:junit4]   2> 16225 T526 C44 P35516 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16226 T535 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2767cff0 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 16226 T526 C44 P35516 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 4
[junit4:junit4]   2> 16227 T574 C43 P35525 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 16227 T574 C43 P35525 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 16230 T531 C44 P35516 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16233 T574 C43 P35525 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty4/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@543d5d50; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 16233 T574 C43 P35525 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 16234 T574 C43 P35525 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16237 T574 C43 P35525 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty4/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@543d5d50; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty4/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@543d5d50; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 16237 T574 C43 P35525 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 16239 T574 C43 P35525 oass.SolrIndexSearcher.<init> Opening Searcher@4b8a2423 main
[junit4:junit4]   2> 16239 T574 C43 P35525 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16240 T573 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4b8a2423 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 16240 T574 C43 P35525 oasc.RecoveryStrategy.replay No replay needed
[junit4:junit4]   2> 16240 T574 C43 P35525 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active
[junit4:junit4]   2> 16242 T574 C43 P35525 oasc.RecoveryStrategy.doRecovery Finished recovery process
[junit4:junit4]   2> 16245 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16335 T521 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16377 T520 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 16377 T559 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 16377 T546 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 16377 T534 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 16377 T572 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 16377 T576 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 17247 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> ASYNC  NEW_CORE C45 name=collection1 org.apache.solr.core.SolrCore@7a4abc92 url=http://127.0.0.1:35513/solr/collection1 node=127.0.0.1:35513_solr
[junit4:junit4]   2> 17256 T512 C45 P35513 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 17259 T512 C45 P35513 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/control/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@306a9eb4; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 17260 T512 C45 P35513 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 17262 T512 C45 P35513 oass.SolrIndexSearcher.<init> Opening Searcher@1324a3a8 main
[junit4:junit4]   2> 17262 T512 C45 P35513 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 17263 T523 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1324a3a8 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 17263 T512 C45 P35513 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 7
[junit4:junit4]   2> 17264 T500 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:35510/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@4a747469
[junit4:junit4]   2> 17265 T580 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:35510
[junit4:junit4]   2> 17265 T580 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:35510, initiating session
[junit4:junit4]   2> 17265 T502 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:61052
[junit4:junit4]   2> 17266 T502 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:61052
[junit4:junit4]   2> 17268 T504 oazs.NIOServerCnxn.finishSessionInit Established session 0x138f3d31bf70008 with negotiated timeout 10000 for client /140.211.11.196:61052
[junit4:junit4]   2> 17268 T580 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:35510, sessionid = 0x138f3d31bf70008, negotiated timeout = 10000
[junit4:junit4]   2> 17269 T581 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4a747469 name:ZooKeeperConnection Watcher:127.0.0.1:35510/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 17269 T500 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 17273 T530 C44 P35516 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 17274 T530 C44 P35516 oass.SolrIndexSearcher.<init> Opening Searcher@1b391f17 main
[junit4:junit4]   2> 17275 T530 C44 P35516 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 17275 T535 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b391f17 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2>  C42_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:35520_solr, base_url=http://127.0.0.1:35520/solr}
[junit4:junit4]   2> 17282 T551 C42 P35520 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 17285 T551 C42 P35520 oass.SolrIndexSearcher.<init> Opening Searcher@15ac6335 main
[junit4:junit4]   2>  C41_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:35518_solr, base_url=http://127.0.0.1:35518/solr}
[junit4:junit4]   2> 17285 T538 C41 P35518 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2>  C43_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:35525_solr, base_url=http://127.0.0.1:35525/solr}
[junit4:junit4]   2> 17285 T564 C43 P35525 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 17285 T551 C42 P35520 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 17287 T560 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@15ac6335 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 17287 T551 C42 P35520 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&softCommit=false&version=2} {commit=} 0 5
[junit4:junit4]   2> 17288 T564 C43 P35525 oass.SolrIndexSearcher.<init> Opening Searcher@3f8e0709 main
[junit4:junit4]   2> 17288 T538 C41 P35518 oass.SolrIndexSearcher.<init> Opening Searcher@7c2ec911 main
[junit4:junit4]   2> 17288 T564 C43 P35525 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 17288 T538 C41 P35518 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 17289 T573 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3f8e0709 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 17289 T547 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7c2ec911 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 17289 T564 C43 P35525 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&softCommit=false&version=2} {commit=} 0 4
[junit4:junit4]   2> 17290 T538 C41 P35518 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&softCommit=false&version=2} {commit=} 0 5
[junit4:junit4]   2> 17290 T530 C44 P35516 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 18
[junit4:junit4]   2> 17292 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 17295 T527 C44 P35516 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 17297 T539 C41 P35518 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 17299 T552 C42 P35520 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 17301 T565 C43 P35525 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 19307 T512 C45 P35513 oass.SolrIndexSearcher.<init> Opening Searcher@3bcf6ac5 realtime
[junit4:junit4]   2> 19308 T512 C45 P35513 /update {wt=javabin&version=2} {deleteByQuery=*:* (-1409412512500154368)} 0 2
[junit4:junit4]   2> 19312 T530 C44 P35516 oass.SolrIndexSearcher.<init> Opening Searcher@65002d1e realtime
[junit4:junit4]   2> 19316 T551 C42 P35520 oass.SolrIndexSearcher.<init> Opening Searcher@3ae4ae12 realtime
[junit4:junit4]   2> 19316 T551 C42 P35520 REQ /update {update.distrib=FROMLEADER&_version_=-1409412512505397248&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19317 T564 C43 P35525 oass.SolrIndexSearcher.<init> Opening Searcher@6b831a25 realtime
[junit4:junit4]   2> 19317 T538 C41 P35518 oass.SolrIndexSearcher.<init> Opening Searcher@236a52cb realtime
[junit4:junit4]   2> 19317 T564 C43 P35525 REQ /update {update.distrib=FROMLEADER&_version_=-1409412512505397248&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19317 T538 C41 P35518 REQ /update {update.distrib=FROMLEADER&_version_=-1409412512505397248&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19318 T530 C44 P35516 /update {wt=javabin&version=2} {deleteByQuery=*:* (-1409412512505397248)} 0 7
[junit4:junit4]   2> 19325 T512 C45 P35513 /update {wt=javabin&version=2} {add=[0 (1409412512516931584)]} 0 4
[junit4:junit4]   2> 19333 T551 C42 P35520 REQ /update {update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19335 T564 C43 P35525 REQ /update {update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19336 T538 C41 P35518 REQ /update {update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 19337 T530 C44 P35516 /update {wt=javabin&version=2} {add=[0 (1409412512524271616)]} 0 9
[junit4:junit4]   2> 19342 T512 C45 P35513 /update {wt=javabin&version=2} {add=[1 (1409412512536854528)]} 0 2
[junit4:junit4]   2> 19350 T551 C42 P35520 REQ /update {update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19351 T564 C43 P35525 REQ /update {update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19351 T538 C41 P35518 REQ /update {update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19352 T530 C44 P35516 /update {wt=javabin&version=2} {add=[1 (1409412512542097408)]} 0 7
[junit4:junit4]   2> 19357 T512 C45 P35513 /update {wt=javabin&version=2} {add=[2 (1409412512552583168)]} 0 2
[junit4:junit4]   2> 19364 T551 C42 P35520 REQ /update {update.distrib=FROMLEADER&test.distrib.skip.servers=http://127.0.0.1:35518/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19366 T564 C43 P35525 REQ /update {update.distrib=FROMLEADER&test.distrib.skip.servers=http://127.0.0.1:35518/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19367 T530 C44 P35516 /update {test.distrib.skip.servers=http://127.0.0.1:35518/solr/collection1/&wt=javabin&version=2} {add=[2 (1409412512557826048)]} 0 7
[junit4:junit4]   2> 19372 T512 C45 P35513 /update {wt=javabin&version=2} {add=[3 (1409412512568311808)]} 0 2
[junit4:junit4]   2> 19381 T564 C43 P35525 REQ /update {update.distrib=FROMLEADER&test.distrib.skip.servers=http://127.0.0.1:35518/solr/collection1/&test.distrib.skip.servers=http://127.0.0.1:35520/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19382 T530 C44 P35516 /update {test.distrib.skip.servers=http://127.0.0.1:35518/solr/collection1/&test.distrib.skip.servers=http://127.0.0.1:35520/solr/collection1/&wt=javabin&version=2} {add=[3 (1409412512573554688)]} 0 7
[junit4:junit4]   2> 19386 T512 C45 P35513 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 19453 T512 C45 P35513 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/control/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@306a9eb4; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/control/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@306a9eb4; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0.fnm, _0.frq, _0.tim, _0_nrm.cfe, segments_2, _0.fdx, _0_nrm.cfs, _0.si, _0.prx, _0.tip, _0.fdt]
[junit4:junit4]   2> 19454 T512 C45 P35513 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 19457 T512 C45 P35513 oass.SolrIndexSearcher.<init> Opening Searcher@3a3d4942 main
[junit4:junit4]   2> 19457 T512 C45 P35513 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 19458 T523 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3a3d4942 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C4)}
[junit4:junit4]   2> 19458 T512 C45 P35513 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 73
[junit4:junit4]   2> 19461 T530 C44 P35516 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 19507 T530 C44 P35516 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty1/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1aac7c9e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty1/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1aac7c9e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0.fnm, _0.frq, _0.tim, _0_nrm.cfe, segments_2, _0.fdx, _0_nrm.cfs, _0.si, _0.prx, _0.tip, _0.fdt]
[junit4:junit4]   2> 19508 T530 C44 P35516 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 19510 T530 C44 P35516 oass.SolrIndexSearcher.<init> Opening Searcher@6b6b3952 main
[junit4:junit4]   2> 19510 T530 C44 P35516 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 19511 T535 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6b6b3952 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C4)}
[junit4:junit4]   2> 19514 T538 C41 P35518 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 19514 T551 C42 P35520 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 19514 T564 C43 P35525 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 19578 T538 C41 P35518 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty2/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@10b7868f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty2/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@10b7868f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[_0.fnm, _0.frq, _0.tim, _0_nrm.cfe, _0.fdx, _0_nrm.cfs, _0.si, _0.prx, _0.tip, _0.fdt, segments_3]
[junit4:junit4]   2> 19578 T538 C41 P35518 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 19579 T564 C43 P35525 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty4/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@543d5d50; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty4/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@543d5d50; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[_0.fnm, _0.frq, _0.tim, _0_nrm.cfe, _0.fdx, _0_nrm.cfs, _0.si, _0.prx, _0.tip, _0.fdt, segments_3]
[junit4:junit4]   2> 19580 T564 C43 P35525 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 19581 T551 C42 P35520 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty3/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d1abe27; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty3/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d1abe27; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[_0.fnm, _0.frq, _0.tim, _0_nrm.cfe, _0.fdx, _0_nrm.cfs, _0.si, _0.prx, _0.tip, _0.fdt, segments_3]
[junit4:junit4]   2> 19581 T538 C41 P35518 oass.SolrIndexSearcher.<init> Opening Searcher@7b5abf90 main
[junit4:junit4]   2> 19581 T551 C42 P35520 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 19582 T538 C41 P35518 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 19582 T547 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7b5abf90 main{StandardDirectoryReader(segments_3:4:nrt _0(5.0):C2)}
[junit4:junit4]   2> 19583 T538 C41 P35518 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&softCommit=false&version=2} {commit=} 0 69
[junit4:junit4]   2> 19584 T564 C43 P35525 oass.SolrIndexSearcher.<init> Opening Searcher@4741c679 main
[junit4:junit4]   2> 19584 T564 C43 P35525 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 19585 T573 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4741c679 main{StandardDirectoryReader(segments_3:4:nrt _0(5.0):C4)}
[junit4:junit4]   2> 19586 T564 C43 P35525 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&softCommit=false&version=2} {commit=} 0 72
[junit4:junit4]   2> 19586 T551 C42 P35520 oass.SolrIndexSearcher.<init> Opening Searcher@2453d391 main
[junit4:junit4]   2> 19587 T551 C42 P35520 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 19588 T560 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2453d391 main{StandardDirectoryReader(segments_3:4:nrt _0(5.0):C3)}
[junit4:junit4]   2> 19588 T551 C42 P35520 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&softCommit=false&version=2} {commit=} 0 74
[junit4:junit4]   2> 19589 T530 C44 P35516 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 128
[junit4:junit4]   2> 19590 T500 oasc.AbstractDistributedZkTestCase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):360
[junit4:junit4]   2> 19591 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> check const of shard1
[junit4:junit4]   2> client0
[junit4:junit4]   2> PROPS:shard=shard1
[junit4:junit4]   2> leader=true
[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:35516_solr
[junit4:junit4]   2> base_url=http://127.0.0.1:35516/solr
[junit4:junit4]   2> 
[junit4:junit4]   2> 19595 T527 C44 P35516 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=4 status=0 QTime=1 
[junit4:junit4]   2>  live:true
[junit4:junit4]   2>  num:4
[junit4:junit4]   2> 
[junit4:junit4]   2> client1
[junit4:junit4]   2> PROPS: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:35518_solr
[junit4:junit4]   2> base_url=http://127.0.0.1:35518/solr
[junit4:junit4]   2> 
[junit4:junit4]   2> 19601 T539 C41 P35518 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=2 status=0 QTime=1 
[junit4:junit4]   2>  live:true
[junit4:junit4]   2>  num:2
[junit4:junit4]   2> 
[junit4:junit4]   2> ######shard1 is not consistent.  Got 4 from org.apache.solr.client.solrj.impl.HttpSolrServer@63d9dfa4lastClient and got 2 from http://127.0.0.1:35518/solr/collection1
[junit4:junit4]   2> 19607 T527 C44 P35516 REQ /select {fl=id,_version_&sort=id+asc&q=*:*&distrib=false&wt=javabin&rows=1000&version=2} hits=4 status=0 QTime=3 
[junit4:junit4]   2> 19611 T539 C41 P35518 REQ /select {fl=id,_version_&sort=id+asc&q=*:*&distrib=false&wt=javabin&rows=1000&version=2} hits=2 status=0 QTime=1 
[junit4:junit4]   2> ######org.apache.solr.client.solrj.impl.HttpSolrServer@63d9dfa4: {numFound=4,start=0,docs=[SolrDocument{id=0, _version_=1409412512524271616}, SolrDocument{id=1, _version_=1409412512542097408}, SolrDocument{id=2, _version_=1409412512557826048}, SolrDocument{id=3, _version_=1409412512573554688}]}
[junit4:junit4]   2> ######org.apache.solr.client.solrj.impl.HttpSolrServer@71854a6: {numFound=2,start=0,docs=[SolrDocument{id=0, _version_=1409412512524271616}, SolrDocument{id=1, _version_=1409412512542097408}]}
[junit4:junit4]   2> ###### sizes=4,2
[junit4:junit4]   2> ###### Only in org.apache.solr.client.solrj.impl.HttpSolrServer@63d9dfa4: [{id=2, _version_=1409412512557826048}, {id=3, _version_=1409412512573554688}]
[junit4:junit4]   2> client2
[junit4:junit4]   2> PROPS: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:35520_solr
[junit4:junit4]   2> base_url=http://127.0.0.1:35520/solr
[junit4:junit4]   2> 
[junit4:junit4]   2> 19614 T552 C42 P35520 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=3 status=0 QTime=0 
[junit4:junit4]   2>  live:true
[junit4:junit4]   2>  num:3
[junit4:junit4]   2> 
[junit4:junit4]   2> client3
[junit4:junit4]   2> PROPS: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:35525_solr
[junit4:junit4]   2> base_url=http://127.0.0.1:35525/solr
[junit4:junit4]   2> 
[junit4:junit4]   2> 19619 T565 C43 P35525 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=4 status=0 QTime=1 
[junit4:junit4]   2>  live:true
[junit4:junit4]   2>  num:4
[junit4:junit4]   2> 
[junit4:junit4]   2> 19621 T500 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 19632 T553 oasha.CollectionsHandler.handleSyncShardAction Syncing shard : action=SYNCSHARD&collection=collection1&shard=shard1&wt=javabin&version=2
[junit4:junit4]   2> 19632 T553 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 19641 T532 oasha.CoreAdminHandler.handleRequestSyncAction I have been requested to sync up my shard
[junit4:junit4]   2> 19642 T532 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:35516/solr/collection1/
[junit4:junit4]   2> 19642 T532 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35516/solr START replicas=[http://127.0.0.1:35518/solr/collection1/, http://127.0.0.1:35520/solr/collection1/, http://127.0.0.1:35525/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 19645 T566 C43 P35525 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 19645 T554 C42 P35520 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=0 
[junit4:junit4]   2> 19645 T540 C41 P35518 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 19650 T532 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:35516/solr  Received 5 versions from 127.0.0.1:35525/solr/collection1/
[junit4:junit4]   2> 19651 T532 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:35516/solr  Our versions are newer. ourLowThreshold=1409412512505397248 otherHigh=1409412512557826048
[junit4:junit4]   2> 19651 T532 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:35516/solr  Received 4 versions from 127.0.0.1:35520/solr/collection1/
[junit4:junit4]   2> 19651 T532 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:35516/solr  Our versions are newer. ourLowThreshold=1409412512505397248 otherHigh=1409412512557826048
[junit4:junit4]   2> 19652 T532 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:35516/solr  Received 3 versions from 127.0.0.1:35518/solr/collection1/
[junit4:junit4]   2> 19652 T532 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:35516/solr  Our versions are newer. ourLowThreshold=1409412512505397248 otherHigh=1409412512542097408
[junit4:junit4]   2> 19652 T532 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35516/solr DONE. sync succeeded
[junit4:junit4]   2> 19652 T532 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 19653 T532 oasc.SyncStrategy.syncToMe http://127.0.0.1:35516/solr/collection1/: try and ask http://127.0.0.1:35518/solr/collection1/ to sync
[junit4:junit4]   2> 19653 T532 oasc.SyncStrategy.syncToMe http://127.0.0.1:35516/solr/collection1/: try and ask http://127.0.0.1:35520/solr/collection1/ to sync
[junit4:junit4]   2> 19653 T532 oasc.SyncStrategy.syncToMe http://127.0.0.1:35516/solr/collection1/: try and ask http://127.0.0.1:35525/solr/collection1/ to sync
[junit4:junit4]   2> 19655 T541 C41 P35518 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35518/solr START replicas=[http://127.0.0.1:35516/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 19655 T555 C42 P35520 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35520/solr START replicas=[http://127.0.0.1:35516/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 19655 T567 C43 P35525 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35525/solr START replicas=[http://127.0.0.1:35516/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 19657 T528 C44 P35516 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 19657 T526 C44 P35516 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=0 
[junit4:junit4]   2> 19657 T529 C44 P35516 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=0 
[junit4:junit4]   2> 19658 T555 C42 P35520 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:35520/solr  Received 5 versions from 127.0.0.1:35516/solr/collection1/
[junit4:junit4]   2> 19658 T541 C41 P35518 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:35518/solr  Received 5 versions from 127.0.0.1:35516/solr/collection1/
[junit4:junit4]   2> 19658 T567 C43 P35525 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:35525/solr  Received 5 versions from 127.0.0.1:35516/solr/collection1/
[junit4:junit4]   2> 19658 T555 C42 P35520 oasu.PeerSync.requestUpdates PeerSync: core=collection1 url=http://127.0.0.1:35520/solr Requesting updates from 127.0.0.1:35516/solr/collection1/n=1 versions=[1409412512573554688]
[junit4:junit4]   2> 19658 T567 C43 P35525 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:35525/solr  Our versions are newer. ourLowThreshold=1409412512505397248 otherHigh=1409412512557826048
[junit4:junit4]   2> 19658 T541 C41 P35518 oasu.PeerSync.requestUpdates PeerSync: core=collection1 url=http://127.0.0.1:35518/solr Requesting updates from 127.0.0.1:35516/solr/collection1/n=2 versions=[1409412512573554688, 1409412512557826048]
[junit4:junit4]   2> 19659 T567 C43 P35525 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35525/solr DONE. sync succeeded
[junit4:junit4]   2> 19659 T567 C43 P35525 REQ /get {sync=http://127.0.0.1:35516/solr/collection1/&getVersions=100&distrib=false&qt=/get&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 19660 T532 oasc.SyncStrategy.syncToMe http://127.0.0.1:35516/solr/collection1/:  sync completed with http://127.0.0.1:35525/solr/collection1/
[junit4:junit4]   2> 19662 T529 C44 P35516 REQ /get {distrib=false&getUpdates=1409412512573554688,1409412512557826048&qt=/get&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19662 T526 C44 P35516 REQ /get {distrib=false&getUpdates=1409412512573554688&qt=/get&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 19665 T555 C42 P35520 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35520/solr DONE. sync succeeded
[junit4:junit4]   2> 19665 T555 C42 P35520 REQ /get {sync=http://127.0.0.1:35516/solr/collection1/&getVersions=100&distrib=false&qt=/get&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 19666 T532 oasc.SyncStrategy.syncToMe http://127.0.0.1:35516/solr/collection1/:  sync completed with http://127.0.0.1:35520/solr/collection1/
[junit4:junit4]   2> 19666 T541 C41 P35518 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35518/solr DONE. sync succeeded
[junit4:junit4]   2> 19666 T541 C41 P35518 REQ /get {sync=http://127.0.0.1:35516/solr/collection1/&getVersions=100&distrib=false&qt=/get&wt=javabin&version=2} status=0 QTime=12 
[junit4:junit4]   2> 19667 T532 oasc.SyncStrategy.syncToMe http://127.0.0.1:35516/solr/collection1/:  sync completed with http://127.0.0.1:35518/solr/collection1/
[junit4:junit4]   2> 19668 T500 oasc.AbstractDistributedZkTestCase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):360
[junit4:junit4]   2> 19669 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19672 T512 C45 P35513 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 19673 T512 C45 P35513 oass.SolrIndexSearcher.<init> Opening Searcher@6d21978b main
[junit4:junit4]   2> 19674 T512 C45 P35513 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 19674 T523 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6d21978b main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C4)}
[junit4:junit4]   2> 19674 T512 C45 P35513 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 2
[junit4:junit4]   2> 19677 T530 C44 P35516 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 19678 T530 C44 P35516 oass.SolrIndexSearcher.<init> Opening Searcher@45820136 main
[junit4:junit4]   2> 19678 T530 C44 P35516 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 19679 T535 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@45820136 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C4)}
[junit4:junit4]   2> 19683 T564 C43 P35525 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 19683 T538 C41 P35518 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 19683 T551 C42 P35520 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 19684 T564 C43 P35525 oass.SolrIndexSearcher.<init> Opening Searcher@419a2fd6 main
[junit4:junit4]   2> 19686 T564 C43 P35525 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 19687 T573 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@419a2fd6 main{StandardDirectoryReader(segments_3:4:nrt _0(5.0):C4)}
[junit4:junit4]   2> 19687 T564 C43 P35525 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&softCommit=false&version=2} {commit=} 0 5
[junit4:junit4]   2> 19768 T538 C41 P35518 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty2/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@10b7868f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[_0.fnm, _0.frq, _0.tim, _0_nrm.cfe, _0.fdx, _0_nrm.cfs, _0.si, _0.prx, _0.tip, _0.fdt, segments_3]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty2/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@10b7868f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_4,generation=4,filenames=[_1_nrm.cfs, _0.fnm, _1.frq, _0_nrm.cfs, _1.fnm, _1_nrm.cfe, _1.fdx, _1.prx, _1.fdt, _1.si, _0_nrm.cfe, _0.tim, _0.frq, _0.fdx, _0.si, _1.tip, _0.tip, _0.prx, _1.tim, _0.fdt, segments_4]
[junit4:junit4]   2> 19769 T538 C41 P35518 oasc.SolrDeletionPolicy.updateCommits newest commit = 4
[junit4:junit4]   2> 19771 T538 C41 P35518 oass.SolrIndexSearcher.<init> Opening Searcher@33160dd0 main
[junit4:junit4]   2> 19772 T538 C41 P35518 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 19773 T547 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@33160dd0 main{StandardDirectoryReader(segments_4:6:nrt _0(5.0):C2 _1(5.0):C2)}
[junit4:junit4]   2> 19773 T538 C41 P35518 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&softCommit=false&version=2} {commit=} 0 91
[junit4:junit4]   2> 19780 T551 C42 P35520 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty3/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d1abe27; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[_0.fnm, _0.frq, _0.tim, _0_nrm.cfe, _0.fdx, _0_nrm.cfs, _0.si, _0.prx, _0.tip, _0.fdt, segments_3]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty3/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d1abe27; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_4,generation=4,filenames=[_1_nrm.cfs, _0.fnm, _1.frq, _0_nrm.cfs, _1.fnm, _1_nrm.cfe, _1.fdx, _1.prx, _1.fdt, _1.si, _0_nrm.cfe, _0.tim, _0.frq, _0.fdx, _0.si, _1.tip, _0.tip, _0.prx, _1.tim, _0.fdt, segments_4]
[junit4:junit4]   2> 19780 T551 C42 P35520 oasc.SolrDeletionPolicy.updateCommits newest commit = 4
[junit4:junit4]   2> 19783 T551 C42 P35520 oass.SolrIndexSearcher.<init> Opening Searcher@a72ad73 main
[junit4:junit4]   2> 19784 T551 C42 P35520 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 19785 T560 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@a72ad73 main{StandardDirectoryReader(segments_4:6:nrt _0(5.0):C3 _1(5.0):C1)}
[junit4:junit4]   2> 19785 T551 C42 P35520 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&softCommit=false&version=2} {commit=} 0 103
[junit4:junit4]   2> 19786 T530 C44 P35516 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 109
[junit4:junit4]   2> 19787 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19791 T527 C44 P35516 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=4 status=0 QTime=1 
[junit4:junit4]   2> 19794 T539 C41 P35518 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=4 status=0 QTime=0 
[junit4:junit4]   2> 19798 T552 C42 P35520 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=4 status=0 QTime=0 
[junit4:junit4]   2> 19802 T565 C43 P35525 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=4 status=0 QTime=0 
[junit4:junit4]   2> 21810 T513 C45 P35513 REQ /select {fl=id,score&shard.url=127.0.0.1:35513/solr/collection1/&NOW=1344120516894&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=4 status=0 QTime=0 
[junit4:junit4]   2> 21815 T513 C45 P35513 REQ /select {shard.url=127.0.0.1:35513/solr/collection1/&NOW=1344120516894&q=*:*&ids=3,2,1,0&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21816 T512 C45 P35513 REQ /select {wt=javabin&q=*:*&version=2} status=0 QTime=9 
[junit4:junit4]   2> Control Docs:4
[junit4:junit4]   2> 21817 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> check const of shard1
[junit4:junit4]   2> client0
[junit4:junit4]   2> PROPS:shard=shard1
[junit4:junit4]   2> leader=true
[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:35516_solr
[junit4:junit4]   2> base_url=http://127.0.0.1:35516/solr
[junit4:junit4]   2> 
[junit4:junit4]   2> 21822 T527 C44 P35516 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=4 status=0 QTime=1 
[junit4:junit4]   2>  live:true
[junit4:junit4]   2>  num:4
[junit4:junit4]   2> 
[junit4:junit4]   2> client1
[junit4:junit4]   2> PROPS: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:35518_solr
[junit4:junit4]   2> base_url=http://127.0.0.1:35518/solr
[junit4:junit4]   2> 
[junit4:junit4]   2> 21825 T539 C41 P35518 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=4 status=0 QTime=0 
[junit4:junit4]   2>  live:true
[junit4:junit4]   2>  num:4
[junit4:junit4]   2> 
[junit4:junit4]   2> client2
[junit4:junit4]   2> PROPS: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:35520_solr
[junit4:junit4]   2> base_url=http://127.0.0.1:35520/solr
[junit4:junit4]   2> 
[junit4:junit4]   2> 21829 T552 C42 P35520 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=4 status=0 QTime=0 
[junit4:junit4]   2>  live:true
[junit4:junit4]   2>  num:4
[junit4:junit4]   2> 
[junit4:junit4]   2> client3
[junit4:junit4]   2> PROPS: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:35525_solr
[junit4:junit4]   2> base_url=http://127.0.0.1:35525/solr
[junit4:junit4]   2> 
[junit4:junit4]   2> 21833 T565 C43 P35525 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=4 status=0 QTime=0 
[junit4:junit4]   2>  live:true
[junit4:junit4]   2>  num:4
[junit4:junit4]   2> 
[junit4:junit4]   2> 21839 T596 C44 P35516 REQ /select {fl=id,score&shard.url=127.0.0.1:35516/solr/collection1/|127.0.0.1:35518/solr/collection1/|127.0.0.1:35520/solr/collection1/|127.0.0.1:35525/solr/collection1/&NOW=1344120516923&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=4 status=0 QTime=1 
[junit4:junit4]   2> 21843 T596 C44 P35516 REQ /select {shard.url=127.0.0.1:35516/solr/collection1/|127.0.0.1:35518/solr/collection1/|127.0.0.1:35520/solr/collection1/|127.0.0.1:35525/solr/collection1/&NOW=1344120516923&q=*:*&ids=3,2,1,0&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21844 T568 C43 P35525 REQ /select {wt=javabin&q=*:*&version=2} status=0 QTime=7 
[junit4:junit4]   2> 21849 T512 C45 P35513 /update {wt=javabin&version=2} {add=[4 (1409412515165634560)]} 0 2
[junit4:junit4]   2> 21858 T551 C42 P35520 REQ /update {update.distrib=FROMLEADER&test.distrib.skip.servers=http://127.0.0.1:35525/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 21858 T538 C41 P35518 REQ /update {update.distrib=FROMLEADER&test.distrib.skip.servers=http://127.0.0.1:35525/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 21859 T530 C44 P35516 /update {test.distrib.skip.servers=http://127.0.0.1:35525/solr/collection1/&wt=javabin&version=2} {add=[4 (1409412515169828864)]} 0 7
[junit4:junit4]   2> 21860 T500 oasc.ChaosMonkey.monkeyLog monkey: kill shard! 35516
[junit4:junit4]   2> 21861 T500 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=650296839
[junit4:junit4]   2> 21861 T500 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@287b65b8
[junit4:junit4]   2> 21863 T500 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 21864 T500 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=6,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=1,adds=1,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=5,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4]   2> 21932 T500 C44 P35516 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=3
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty1/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1aac7c9e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty1/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1aac7c9e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0.fnm, _0.frq, _0.tim, _0_nrm.cfe, segments_2, _0.fdx, _0_nrm.cfs, _0.si, _0.prx, _0.tip, _0.fdt]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty1/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1aac7c9e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[_1_nrm.cfs, _0.fnm, _1.frq, _0_nrm.cfs, _1.fnm, _1_nrm.cfe, _1.fdx, _1.prx, _1.fdt, _1.si, _0_nrm.cfe, _0.tim, _0.frq, _0.fdx, _0.si, _1.tip, _0.tip, _0.prx, _1.tim, segments_3, _0.fdt]
[junit4:junit4]   2> 21933 T500 C44 P35516 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 21936 T505 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x138f3d31bf70003
[junit4:junit4]   2> 21937 T576 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 21937 T581 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 21937 T559 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 21937 T534 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 21938 T520 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 21938 T572 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 21938 T534 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 21938 T502 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:35517 which had sessionid 0x138f3d31bf70003
[junit4:junit4]   2> 21938 T534 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 21938 T500 oaz.ZooKeeper.close Session: 0x138f3d31bf70003 closed
[junit4:junit4]   2> 21939 T500 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   2> 21940 T546 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:35518/solr/collection1/
[junit4:junit4]   2> 21940 T546 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35518/solr START replicas=[http://127.0.0.1:35520/solr/collection1/, http://127.0.0.1:35525/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 21944 T554 C42 P35520 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 21944 T566 C43 P35525 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 21944 T546 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:35518/solr  Received 5 versions from 127.0.0.1:35525/solr/collection1/
[junit4:junit4]   2> 21945 T546 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:35518/solr  Our versions are newer. ourLowThreshold=1409412512524271616 otherHigh=1409412512557826048
[junit4:junit4]   2> 21945 T546 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:35518/solr  Received 6 versions from 127.0.0.1:35520/solr/collection1/
[junit4:junit4]   2> 21945 T546 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:35518/solr  Our versions are newer. ourLowThreshold=1409412512524271616 otherHigh=1409412512573554688
[junit4:junit4]   2> 21945 T546 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35518/solr DONE. sync succeeded
[junit4:junit4]   2> 21946 T546 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 21946 T546 oasc.SyncStrategy.syncToMe http://127.0.0.1:35518/solr/collection1/: try and ask http://127.0.0.1:35516/solr/collection1/ to sync
[junit4:junit4]   2> 21946 T546 oasc.SyncStrategy.syncToMe http://127.0.0.1:35518/solr/collection1/: try and ask http://127.0.0.1:35520/solr/collection1/ to sync
[junit4:junit4]   2> 21947 T546 oasc.SyncStrategy.syncToMe http://127.0.0.1:35518/solr/collection1/: try and ask http://127.0.0.1:35525/solr/collection1/ to sync
[junit4:junit4]   2> 21949 T567 C43 P35525 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35525/solr START replicas=[http://127.0.0.1:35518/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 21949 T555 C42 P35520 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35520/solr START replicas=[http://127.0.0.1:35518/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 21952 T542 C41 P35518 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 21953 T567 C43 P35525 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:35525/solr  Received 6 versions from 127.0.0.1:35518/solr/collection1/
[junit4:junit4]   2> 21953 T540 C41 P35518 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 21953 T567 C43 P35525 oasu.PeerSync.requestUpdates PeerSync: core=collection1 url=http://127.0.0.1:35525/solr Requesting updates from 127.0.0.1:35518/solr/collection1/n=1 versions=[1409412515169828864]
[junit4:junit4]   2> 21957 T542 C41 P35518 REQ /get {distrib=false&getUpdates=1409412515169828864&qt=/get&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 21957 T555 C42 P35520 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:35520/solr  Received 6 versions from 127.0.0.1:35518/solr/collection1/
[junit4:junit4]   2> 21958 T555 C42 P35520 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:35520/solr  Our versions are newer. ourLowThreshold=1409412512524271616 otherHigh=1409412512573554688
[junit4:junit4]   2> 21958 T555 C42 P35520 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35520/solr DONE. sync succeeded
[junit4:junit4]   2> 21958 T555 C42 P35520 REQ /get {sync=http://127.0.0.1:35518/solr/collection1/&getVersions=100&distrib=false&qt=/get&wt=javabin&version=2} status=0 QTime=9 
[junit4:junit4]   2> 21959 T546 oasc.SyncStrategy.syncToMe http://127.0.0.1:35518/solr/collection1/:  sync completed with http://127.0.0.1:35520/solr/collection1/
[junit4:junit4]   2> 21960 T567 C43 P35525 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35525/solr DONE. sync succeeded
[junit4:junit4]   2> 21961 T567 C43 P35525 REQ /get {sync=http://127.0.0.1:35518/solr/collection1/&getVersions=100&distrib=false&qt=/get&wt=javabin&version=2} status=0 QTime=12 
[junit4:junit4]   2> 21961 T546 oasc.SyncStrategy.syncToMe http://127.0.0.1:35518/solr/collection1/:  sync completed with http://127.0.0.1:35525/solr/collection1/
[junit4:junit4]   2> 51948 T546 oasc.SolrException.log SEVERE Sync request error: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:35516/solr/collection1
[junit4:junit4]   2> 51948 T546 oasc.SyncStrategy.syncToMe http://127.0.0.1:35518/solr/collection1/: Sync failed - asking replica (http://127.0.0.1:35516/solr/collection1/) to recover.
[junit4:junit4]   2> 51948 T546 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 96957 T546 oasc.SolrException.log SEVERE http://127.0.0.1:35518/solr/collection1/: Could not tell a replica to recover:org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:35516/solr
[junit4:junit4]   2> 		at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:414)
[junit4:junit4]   2> 		at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:182)
[junit4:junit4]   2> 		at org.apache.solr.cloud.SyncStrategy.requestRecovery(SyncStrategy.java:281)
[junit4:junit4]   2> 		at org.apache.solr.cloud.SyncStrategy.syncToMe(SyncStrategy.java:225)
[junit4:junit4]   2> 		at org.apache.solr.cloud.SyncStrategy.syncReplicas(SyncStrategy.java:118)
[junit4:junit4]   2> 		at org.apache.solr.cloud.SyncStrategy.sync(SyncStrategy.java:85)
[junit4:junit4]   2> 		at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:157)
[junit4:junit4]   2> 		at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:151)
[junit4:junit4]   2> 		at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:96)
[junit4:junit4]   2> 		at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:57)
[junit4:junit4]   2> 		at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:125)
[junit4:junit4]   2> 		at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:526)
[junit4:junit4]   2> 		at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:502)
[junit4:junit4]   2> 	Caused by: org.apache.http.conn.ConnectTimeoutException: Connect to 127.0.0.1:35516 timed out
[junit4:junit4]   2> 		at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:125)
[junit4:junit4]   2> 		at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:148)
[junit4:junit4]   2> 		at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:150)
[junit4:junit4]   2> 		at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:121)
[junit4:junit4]   2> 		at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:575)
[junit4:junit4]   2> 		at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:425)
[junit4:junit4]   2> 		at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:820)
[junit4:junit4]   2> 		at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:754)
[junit4:junit4]   2> 		at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:732)
[junit4:junit4]   2> 		at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:353)
[junit4:junit4]   2> 		... 12 more
[junit4:junit4]   2> 	
[junit4:junit4]   2> 96958 T546 oasc.RecoveryStrategy.close WARNING Stopping recovery for core collection1 zkNodeName=127.0.0.1:35518_solr_collection1
[junit4:junit4]   2> 96960 T546 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 96963 T505 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x138f3d31bf70004 type:create cxid:0x55 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 96965 T546 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 97067 T500 oasc.AbstractDistributedZkTestCase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):360
[junit4:junit4]   2> 97068 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 97071 T512 C45 P35513 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 97109 T512 C45 P35513 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/control/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@306a9eb4; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0.fnm, _0.frq, _0.tim, _0_nrm.cfe, segments_2, _0.fdx, _0_nrm.cfs, _0.si, _0.prx, _0.tip, _0.fdt]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/control/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@306a9eb4; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[_1_nrm.cfs, _0.fnm, _1.frq, _0_nrm.cfs, _1.fnm, _1_nrm.cfe, _1.fdx, _1.prx, _1.fdt, _1.si, _0_nrm.cfe, _0.tim, _0.frq, _0.fdx, _0.si, _1.tip, _0.tip, _0.prx, _1.tim, segments_3, _0.fdt]
[junit4:junit4]   2> 97110 T512 C45 P35513 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 97112 T512 C45 P35513 oass.SolrIndexSearcher.<init> Opening Searcher@ff44f15 main
[junit4:junit4]   2> 97112 T512 C45 P35513 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 97113 T523 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ff44f15 main{StandardDirectoryReader(segments_3:5:nrt _0(5.0):C4 _1(5.0):C1)}
[junit4:junit4]   2> 97113 T512 C45 P35513 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 42
[junit4:junit4]   2> 97114 T505 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x138f3d31bf70008
[junit4:junit4]   2> 97116 T581 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 97116 T502 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:61052 which had sessionid 0x138f3d31bf70008
[junit4:junit4]   2> 97116 T500 oaz.ZooKeeper.close Session: 0x138f3d31bf70008 closed
[junit4:junit4]   2> 97117 T505 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x138f3d31bf70007
[junit4:junit4]   2> 97118 T576 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 97118 T502 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:35528 which had sessionid 0x138f3d31bf70007
[junit4:junit4]   2> 97118 T500 oaz.ZooKeeper.close Session: 0x138f3d31bf70007 closed
[junit4:junit4]   2> 97118 T504 oazs.SyncRequestProcessor.run SyncRequestProcessor exited!
[junit4:junit4]   2> 97118 T505 oazs.PrepRequestProcessor.run PrepRequestProcessor exited loop!
[junit4:junit4]   2> 97118 T500 oazs.FinalRequestProcessor.shutdown shutdown of request processor complete
[junit4:junit4]   2> 97337 T502 oazs.NIOServerCnxn$Factory.run WARNING Ignoring unexpected runtime exception java.nio.channels.CancelledKeyException
[junit4:junit4]   2> 	at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:73)
[junit4:junit4]   2> 	at sun.nio.ch.SelectionKeyImpl.readyOps(SelectionKeyImpl.java:87)
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:241)
[junit4:junit4]   2> 
[junit4:junit4]   2> 97337 T500 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:35519 which had sessionid 0x138f3d31bf70004
[junit4:junit4]   2> 97338 T545 oaz.ClientCnxn$SendThread.run Unable to read additional data from server sessionid 0x138f3d31bf70004, likely server has closed socket, closing socket connection and attempting reconnect
[junit4:junit4]   2> 97338 T500 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:35522 which had sessionid 0x138f3d31bf70005
[junit4:junit4]   2> 97338 T558 oaz.ClientCnxn$SendThread.run Unable to read additional data from server sessionid 0x138f3d31bf70005, likely server has closed socket, closing socket connection and attempting reconnect
[junit4:junit4]   2> 97338 T500 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:35514 which had sessionid 0x138f3d31bf70002
[junit4:junit4]   2> 97339 T519 oaz.ClientCnxn$SendThread.run Unable to read additional data from server sessionid 0x138f3d31bf70002, likely server has closed socket, closing socket connection and attempting reconnect
[junit4:junit4]   2> 97339 T500 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:35526 which had sessionid 0x138f3d31bf70006
[junit4:junit4]   2> 97339 T571 oaz.ClientCnxn$SendThread.run Unable to read additional data from server sessionid 0x138f3d31bf70006, likely server has closed socket, closing socket connection and attempting reconnect
[junit4:junit4]   2> 97339 T502 oazs.NIOServerCnxn$Factory.run NIOServerCnxn factory exited run method
[junit4:junit4]   2> 97340 T500 oazs.FinalRequestProcessor.shutdown shutdown of request processor complete
[junit4:junit4]   2> 97340 T500 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 35513
[junit4:junit4]   2> 97340 T500 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=948223506
[junit4:junit4]   2> 97340 T500 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@7a4abc92
[junit4:junit4]   2> 97342 T500 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 97343 T500 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=4,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=5,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4]   2> 97439 T546 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4bf29b82 name:ZooKeeperConnection Watcher:127.0.0.1:35510/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
[junit4:junit4]   2> 97439 T559 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c79d3cf name:ZooKeeperConnection Watcher:127.0.0.1:35510/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
[junit4:junit4]   2> 97440 T572 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5fe82926 name:ZooKeeperConnection Watcher:127.0.0.1:35510/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
[junit4:junit4]   2> 97440 T520 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a00ad7c name:ZooKeeperConnection Watcher:127.0.0.1:35510/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
[junit4:junit4]   2> 97440 T521 oasc.Overseer$ClusterStateUpdater.amILeader WARNING  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4:junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:118)
[junit4:junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
[junit4:junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:927)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:289)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:286)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:67)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:286)
[junit4:junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.amILeader(Overseer.java:187)
[junit4:junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:113)
[junit4:junit4]   2> 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 
[junit4:junit4]   2> 97440 T520 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 97440 T522 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 97440 T500 oaz.ZooKeeper.close Session: 0x138f3d31bf70002 closed
[junit4:junit4]   2> 97441 T521 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=88088280766545922-127.0.0.1:35513_solr-n_0000000000) am no longer a leader.
[junit4:junit4]   2> 97442 T500 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   2> 97494 T500 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 35516
[junit4:junit4]   2> 97494 T500 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 35518
[junit4:junit4]   2> 97494 T500 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1648862199
[junit4:junit4]   2> 97494 T500 oasc.RecoveryStrategy.close WARNING Stopping recovery for core collection1 zkNodeName=127.0.0.1:35518_solr_collection1
[junit4:junit4]   2> 97494 T500 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@14078a2d
[junit4:junit4]   2> 97496 T500 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 97496 T500 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=4,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=1,adds=1,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=5,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4]   2> 97527 T500 C41 P35518 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty2/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@10b7868f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_4,generation=4,filenames=[_1_nrm.cfs, _0.fnm, _1.frq, _0_nrm.cfs, _1.fnm, _1_nrm.cfe, _1.fdx, _1.prx, _1.fdt, _1.si, _0_nrm.cfe, _0.tim, _0.frq, _0.fdx, _0.si, _1.tip, _0.tip, _0.prx, _1.tim, _0.fdt, segments_4]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty2/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@10b7868f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_5,generation=5,filenames=[_2.si, _1.frq, _1.fnm, _2.tim, _2_nrm.cfe, _2_nrm.cfs, _0.si, _0.prx, _1.tip, _1.tim, _1_nrm.cfs, _0.fnm, _2.prx, _2.fdt, _2.frq, _0_nrm.cfs, _2.fdx, _2.fnm, _1_nrm.cfe, _1.prx, _1.fdx, _2.tip, _1.fdt, _1.si, _0.frq, _0.tim, _0_nrm.cfe, _0.fdx, segments_5, _0.tip, _0.fdt]
[junit4:junit4]   2> 97528 T500 C41 P35518 oasc.SolrDeletionPolicy.updateCommits newest commit = 5
[junit4:junit4]   2> 97529 T500 oasc.RecoveryStrategy.close WARNING Stopping recovery for core collection1 zkNodeName=127.0.0.1:35518_solr_collection1
[junit4:junit4]   2> 98914 T503 oazs.SessionTrackerImpl.run SessionTrackerImpl exited loop!
[junit4:junit4]   2> 99043 T545 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server localhost/127.0.0.1:35510
[junit4:junit4]   2> 99130 T558 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server localhost/127.0.0.1:35510
[junit4:junit4]   2> 99382 T571 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server localhost/127.0.0.1:35510
[junit4:junit4]   2> 105541 T546 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 105541 T500 oaz.ZooKeeper.close Session: 0x138f3d31bf70004 closed
[junit4:junit4]   2> 105542 T500 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   2> 105595 T500 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 35520
[junit4:junit4]   2> 105595 T500 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1699526318
[junit4:junit4]   2> 105595 T500 oasc.RecoveryStrategy.close WARNING Stopping recovery for core collection1 zkNodeName=127.0.0.1:35520_solr_collection1
[junit4:junit4]   2> 105595 T500 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@603641c6
[junit4:junit4]   2> 105597 T500 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 105597 T500 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=4,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=1,adds=1,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=5,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4]   2> 105649 T500 C42 P35520 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty3/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d1abe27; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_4,generation=4,filenames=[_1_nrm.cfs, _0.fnm, _1.frq, _0_nrm.cfs, _1.fnm, _1_nrm.cfe, _1.fdx, _1.prx, _1.fdt, _1.si, _0_nrm.cfe, _0.tim, _0.frq, _0.fdx, _0.si, _1.tip, _0.tip, _0.prx, _1.tim, _0.fdt, segments_4]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty3/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d1abe27; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_5,generation=5,filenames=[_2.si, _1.frq, _1.fnm, _2.tim, _2_nrm.cfe, _2_nrm.cfs, _0.si, _0.prx, _1.tip, _1.tim, _1_nrm.cfs, _0.fnm, _2.prx, _2.fdt, _2.frq, _0_nrm.cfs, _2.fdx, _2.fnm, _1_nrm.cfe, _1.prx, _1.fdx, _2.tip, _1.fdt, _1.si, _0.frq, _0.tim, _0_nrm.cfe, _0.fdx, segments_5, _0.tip, _0.fdt]
[junit4:junit4]   2> 105650 T500 C42 P35520 oasc.SolrDeletionPolicy.updateCommits newest commit = 5
[junit4:junit4]   2> 105652 T500 oasc.RecoveryStrategy.close WARNING Stopping recovery for core collection1 zkNodeName=127.0.0.1:35520_solr_collection1
[junit4:junit4]   2> 105753 T559 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 105753 T500 oaz.ZooKeeper.close Session: 0x138f3d31bf70005 closed
[junit4:junit4]   2> 105754 T500 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   2> 105806 T500 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 35525
[junit4:junit4]   2> 105806 T500 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1493638406
[junit4:junit4]   2> 105806 T500 oasc.RecoveryStrategy.close WARNING Stopping recovery for core collection1 zkNodeName=127.0.0.1:35525_solr_collection1
[junit4:junit4]   2> 105806 T500 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@19f00e8b
[junit4:junit4]   2> 105808 T500 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 105808 T500 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=4,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=1,adds=1,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=5,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4]   2> 105853 T500 C43 P35525 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty4/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@543d5d50; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[_0.fnm, _0.frq, _0.tim, _0_nrm.cfe, _0.fdx, _0_nrm.cfs, _0.si, _0.prx, _0.tip, _0.fdt, segments_3]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1344120495090/jetty4/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@543d5d50; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_4,generation=4,filenames=[_1_nrm.cfs, _0.fnm, _1.frq, _0_nrm.cfs, _1.fnm, _1_nrm.cfe, _1.fdx, _1.prx, _1.fdt, _1.si, _0_nrm.cfe, _0.tim, _0.frq, _0.fdx, _0.si, _1.tip, _0.tip, _0.prx, _1.tim, _0.fdt, segments_4]
[junit4:junit4]   2> 105854 T500 C43 P35525 oasc.SolrDeletionPolicy.updateCommits newest commit = 4
[junit4:junit4]   2> 105855 T500 oasc.RecoveryStrategy.close WARNING Stopping recovery for core collection1 zkNodeName=127.0.0.1:35525_solr_collection1
[junit4:junit4]   2> 105956 T572 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 105956 T500 oaz.ZooKeeper.close Session: 0x138f3d31bf70006 closed
[junit4:junit4]   2> 105957 T500 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   2> 106052 T500 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=SyncSliceTest -Dtests.method=testDistribSearch -Dtests.seed=DB32D3B448B10D0A -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en_PH -Dtests.timezone=America/Yellowknife -Dtests.file.encoding=UTF-8
[junit4:junit4]   2>
[junit4:junit4]    > (@AfterClass output)
[junit4:junit4]   2> 106097 T500 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> NOTE: test params are: codec=Asserting, sim=DefaultSimilarity, locale=en_PH, timezone=America/Yellowknife
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Oracle Corporation 1.7.0_04 (64-bit)/cpus=16,threads=1,free=80431168,total=296747008
[junit4:junit4]   2> NOTE: All tests run in this JVM: [StatsComponentTest, SolrRequestParserTest, PathHierarchyTokenizerFactoryTest, TestBinaryField, DistanceFunctionTest, ShowFileRequestHandlerTest, LeaderElectionIntegrationTest, ClusterStateTest, PrimitiveFieldTypeTest, SearchHandlerTest, UpdateRequestProcessorFactoryTest, DirectUpdateHandlerTest, AnalysisAfterCoreReloadTest, IndexBasedSpellCheckerTest, OutputWriterTest, ReturnFieldsTest, DistributedQueryElevationComponentTest, FileUtilsTest, TestIndexingPerformance, CoreContainerCoreInitFailuresTest, TestLFUCache, FullSolrCloudDistribCmdsTest, TestArbitraryIndexDir, QueryElevationComponentTest, TestRandomFaceting, LegacyHTMLStripCharFilterTest, TestCodecSupport, SpellPossibilityIteratorTest, PluginInfoTest, TestSurroundQueryParser, PingRequestHandlerTest, TestDefaultSimilarityFactory, LukeRequestHandlerTest, SolrCoreTest, SyncSliceTest]
[junit4:junit4]   2> 
[junit4:junit4] Completed on J0 in 106.11s, 1 test, 1 error <<< FAILURES!

[...truncated 545 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/build.xml:29: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/solr/build.xml:144: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/lucene/module-build.xml:62: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/lucene/common-build.xml:1095: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-tests-only-trunk-java7/checkout/lucene/common-build.xml:790: There were test failures: 223 suites, 899 tests, 1 error, 5 ignored

Total time: 30 minutes 17 seconds
Build step 'Execute shell' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message