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-4.2.1-java7 - Build # 7 - Failure
Date Fri, 22 Mar 2013 19:59:39 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.2.1-java7/7/

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

Error Message:
Test Setup Failure: shard1 should have just been set up to be inconsistent - but it's still consistent. Leader:http://127.0.0.1:53253/collection1skip list:[CloudJettyRunner [url=http://127.0.0.1:17812/collection1], CloudJettyRunner [url=http://127.0.0.1:17812/collection1]]

Stack Trace:
java.lang.AssertionError: Test Setup Failure: shard1 should have just been set up to be inconsistent - but it's still consistent. Leader:http://127.0.0.1:53253/collection1skip list:[CloudJettyRunner [url=http://127.0.0.1:17812/collection1], CloudJettyRunner [url=http://127.0.0.1:17812/collection1]]
	at __randomizedtesting.SeedInfo.seed([D671551D9010A365:5797DB05E74FC359]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.junit.Assert.assertNotNull(Assert.java:526)
	at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:212)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
	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:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:722)




Build Log:
[...truncated 9212 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.SyncSliceTest
[junit4:junit4]   2> 0 T1835 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4]   2> 5 T1835 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./solrtest-SyncSliceTest-1363981627381
[junit4:junit4]   2> 7 T1835 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 7 T1836 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 10 T1836 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 11 T1836 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4]   2> 11 T1836 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4]   2> 12 T1836 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 13 T1836 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-1363981627381/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4]   2> 108 T1835 oasc.ZkTestServer.run start zk server on port:13523
[junit4:junit4]   2> 108 T1835 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13523 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@7d31de29
[junit4:junit4]   2> 109 T1835 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 110 T1841 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13523. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 110 T1841 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13523, initiating session
[junit4:junit4]   2> 110 T1837 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:41668
[junit4:junit4]   2> 111 T1837 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:41668
[junit4:junit4]   2> 111 T1839 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 114 T1839 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d93a3effd0000 with negotiated timeout 10000 for client /140.211.11.196:41668
[junit4:junit4]   2> 114 T1841 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13523, sessionid = 0x13d93a3effd0000, negotiated timeout = 10000
[junit4:junit4]   2> 115 T1842 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7d31de29 name:ZooKeeperConnection Watcher:127.0.0.1:13523 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 115 T1835 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 116 T1835 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 132 T1840 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d93a3effd0000
[junit4:junit4]   2> 133 T1842 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 134 T1837 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:41668 which had sessionid 0x13d93a3effd0000
[junit4:junit4]   2> 133 T1835 oaz.ZooKeeper.close Session: 0x13d93a3effd0000 closed
[junit4:junit4]   2> 134 T1835 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13523/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@10b33b47
[junit4:junit4]   2> 135 T1835 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 135 T1843 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13523. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 136 T1843 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13523, initiating session
[junit4:junit4]   2> 136 T1837 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:16695
[junit4:junit4]   2> 136 T1837 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:16695
[junit4:junit4]   2> 138 T1839 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d93a3effd0001 with negotiated timeout 10000 for client /140.211.11.196:16695
[junit4:junit4]   2> 138 T1843 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13523, sessionid = 0x13d93a3effd0001, negotiated timeout = 10000
[junit4:junit4]   2> 138 T1844 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10b33b47 name:ZooKeeperConnection Watcher:127.0.0.1:13523/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 138 T1835 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 139 T1835 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 148 T1835 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 151 T1835 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 153 T1835 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 156 T1835 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 157 T1835 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 173 T1835 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 174 T1835 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 277 T1835 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 278 T1835 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 281 T1835 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 281 T1835 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 291 T1835 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 292 T1835 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 295 T1835 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 295 T1835 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 298 T1835 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 299 T1835 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 302 T1835 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 303 T1835 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 305 T1835 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 306 T1835 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 313 T1840 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d93a3effd0001
[junit4:junit4]   2> 314 T1844 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 314 T1837 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:16695 which had sessionid 0x13d93a3effd0001
[junit4:junit4]   2> 314 T1835 oaz.ZooKeeper.close Session: 0x13d93a3effd0001 closed
[junit4:junit4]   2> 499 T1835 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 503 T1835 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:40996
[junit4:junit4]   2> 504 T1835 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 504 T1835 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 505 T1835 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363981627690
[junit4:junit4]   2> 505 T1835 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363981627690/solr.xml
[junit4:junit4]   2> 506 T1835 oasc.CoreContainer.<init> New CoreContainer 931661934
[junit4:junit4]   2> 506 T1835 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363981627690/'
[junit4:junit4]   2> 507 T1835 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363981627690/'
[junit4:junit4]   2> 568 T1835 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 569 T1835 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 570 T1835 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 570 T1835 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 571 T1835 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 571 T1835 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 572 T1835 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 572 T1835 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 572 T1835 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 573 T1835 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 595 T1835 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 615 T1835 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:13523/solr
[junit4:junit4]   2> 616 T1835 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 617 T1835 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13523 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@123701ce
[junit4:junit4]   2> 618 T1835 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 618 T1854 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13523. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 619 T1854 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13523, initiating session
[junit4:junit4]   2> 619 T1837 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:17151
[junit4:junit4]   2> 620 T1837 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:17151
[junit4:junit4]   2> 621 T1839 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d93a3effd0002 with negotiated timeout 20000 for client /140.211.11.196:17151
[junit4:junit4]   2> 622 T1854 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13523, sessionid = 0x13d93a3effd0002, negotiated timeout = 20000
[junit4:junit4]   2> 622 T1855 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@123701ce name:ZooKeeperConnection Watcher:127.0.0.1:13523 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 622 T1835 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 623 T1840 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d93a3effd0002
[junit4:junit4]   2> 632 T1855 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 632 T1837 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:17151 which had sessionid 0x13d93a3effd0002
[junit4:junit4]   2> 632 T1835 oaz.ZooKeeper.close Session: 0x13d93a3effd0002 closed
[junit4:junit4]   2> 632 T1835 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 644 T1835 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13523/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@166ba82c
[junit4:junit4]   2> 645 T1835 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 645 T1856 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13523. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 646 T1856 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13523, initiating session
[junit4:junit4]   2> 646 T1837 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:50074
[junit4:junit4]   2> 647 T1837 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:50074
[junit4:junit4]   2> 648 T1839 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d93a3effd0003 with negotiated timeout 20000 for client /140.211.11.196:50074
[junit4:junit4]   2> 648 T1856 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13523, sessionid = 0x13d93a3effd0003, negotiated timeout = 20000
[junit4:junit4]   2> 648 T1857 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@166ba82c name:ZooKeeperConnection Watcher:127.0.0.1:13523/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 649 T1835 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 651 T1835 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4]   2> 665 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0003 type:create cxid:0x7 zxid:0x1b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 667 T1835 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4]   2> 676 T1835 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 680 T1835 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40996_
[junit4:junit4]   2> 681 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0003 type:delete cxid:0x12 zxid:0x1e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:40996_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:40996_
[junit4:junit4]   2> 683 T1835 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40996_
[junit4:junit4]   2> 687 T1835 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 701 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0003 type:delete cxid:0x20 zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 703 T1835 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 711 T1835 oasc.Overseer.start Overseer (id=89389899932565507-127.0.0.1:40996_-n_0000000000) starting
[junit4:junit4]   2> 712 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0003 type:create cxid:0x25 zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 713 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0003 type:create cxid:0x26 zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 715 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0003 type:create cxid:0x28 zxid:0x27 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 717 T1835 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4]   2> 727 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0003 type:create cxid:0x2e zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 729 T1859 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 730 T1835 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 733 T1835 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4]   2> 735 T1835 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 738 T1858 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 745 T1860 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363981627690/collection1
[junit4:junit4]   2> 746 T1860 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 746 T1860 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 747 T1860 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 748 T1860 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363981627690/collection1/'
[junit4:junit4]   2> 749 T1860 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-controljetty-1363981627690/collection1/lib/README' to classloader
[junit4:junit4]   2> 750 T1860 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-controljetty-1363981627690/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 801 T1860 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 862 T1860 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 963 T1860 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 969 T1860 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1644 T1860 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1661 T1860 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1665 T1860 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1681 T1860 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1687 T1860 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1693 T1860 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1694 T1860 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 1695 T1860 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 1695 T1860 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1696 T1860 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 1697 T1860 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 1697 T1860 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 1697 T1860 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363981627690/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1363981627381/control/data/
[junit4:junit4]   2> 1698 T1860 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4bf4e4c0
[junit4:junit4]   2> 1698 T1860 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 1699 T1860 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363981627381/control/data forceNew: false
[junit4:junit4]   2> 1699 T1860 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1363981627381/control/data/index/
[junit4:junit4]   2> 1700 T1860 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1363981627381/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1700 T1860 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363981627381/control/data/index forceNew: false
[junit4:junit4]   2> 1704 T1860 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3e85c16e lockFactory=org.apache.lucene.store.NativeFSLockFactory@1236e6f9),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1704 T1860 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 1707 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1707 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1708 T1860 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1709 T1860 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1709 T1860 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1710 T1860 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1710 T1860 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1710 T1860 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1711 T1860 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1727 T1860 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1736 T1860 oass.SolrIndexSearcher.<init> Opening Searcher@673db262 main
[junit4:junit4]   2> 1736 T1860 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.SyncSliceTest-1363981627381/control/data/tlog
[junit4:junit4]   2> 1738 T1860 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1738 T1860 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1742 T1861 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@673db262 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1745 T1860 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 1746 T1860 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 2241 T1858 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2242 T1858 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"1",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:40996_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:40996"}
[junit4:junit4]   2> 2242 T1858 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 2242 T1858 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 2259 T1857 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 2749 T1860 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 2749 T1860 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:40996 collection:control_collection shard:shard1
[junit4:junit4]   2> 2750 T1860 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 2767 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0003 type:delete cxid:0x82 zxid:0x35 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 2769 T1860 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 2769 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0003 type:create cxid:0x83 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2780 T1860 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2780 T1860 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2781 T1860 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:40996/collection1/
[junit4:junit4]   2> 2781 T1860 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 2781 T1860 oasc.SyncStrategy.syncToMe http://127.0.0.1:40996/collection1/ has no replicas
[junit4:junit4]   2> 2781 T1860 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:40996/collection1/
[junit4:junit4]   2> 2782 T1860 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 2786 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0003 type:create cxid:0x8e zxid:0x3a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3763 T1858 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3786 T1857 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 3817 T1860 oasc.ZkController.register We are http://127.0.0.1:40996/collection1/ and leader is http://127.0.0.1:40996/collection1/
[junit4:junit4]   2> 3817 T1860 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:40996
[junit4:junit4]   2> 3817 T1860 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 3817 T1860 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 3818 T1860 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 3819 T1860 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3820 T1835 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0
[junit4:junit4]   2> 3821 T1835 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 3822 T1835 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 3839 T1835 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 3840 T1835 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13523/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1e6336f3
[junit4:junit4]   2> 3841 T1835 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3842 T1862 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13523. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 3842 T1862 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13523, initiating session
[junit4:junit4]   2> 3843 T1837 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:30728
[junit4:junit4]   2> 3843 T1837 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:30728
[junit4:junit4]   2> 3845 T1839 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d93a3effd0004 with negotiated timeout 10000 for client /140.211.11.196:30728
[junit4:junit4]   2> 3845 T1862 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13523, sessionid = 0x13d93a3effd0004, negotiated timeout = 10000
[junit4:junit4]   2> 3845 T1863 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e6336f3 name:ZooKeeperConnection Watcher:127.0.0.1:13523/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3845 T1835 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3846 T1835 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3848 T1835 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 4039 T1835 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 4042 T1835 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:20515
[junit4:junit4]   2> 4043 T1835 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 4044 T1835 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4044 T1835 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363981631223
[junit4:junit4]   2> 4045 T1835 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363981631223/solr.xml
[junit4:junit4]   2> 4045 T1835 oasc.CoreContainer.<init> New CoreContainer 1703533844
[junit4:junit4]   2> 4046 T1835 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363981631223/'
[junit4:junit4]   2> 4046 T1835 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363981631223/'
[junit4:junit4]   2> 4107 T1835 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 4108 T1835 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 4108 T1835 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 4109 T1835 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 4109 T1835 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 4110 T1835 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 4110 T1835 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 4111 T1835 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 4111 T1835 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 4112 T1835 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 4134 T1835 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 4153 T1835 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:13523/solr
[junit4:junit4]   2> 4154 T1835 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 4155 T1835 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13523 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@3b14d10e
[junit4:junit4]   2> 4156 T1835 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4156 T1873 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13523. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 4157 T1873 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13523, initiating session
[junit4:junit4]   2> 4157 T1837 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:20635
[junit4:junit4]   2> 4158 T1837 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:20635
[junit4:junit4]   2> 4160 T1839 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d93a3effd0005 with negotiated timeout 20000 for client /140.211.11.196:20635
[junit4:junit4]   2> 4160 T1873 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13523, sessionid = 0x13d93a3effd0005, negotiated timeout = 20000
[junit4:junit4]   2> 4160 T1874 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b14d10e name:ZooKeeperConnection Watcher:127.0.0.1:13523 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4160 T1835 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4161 T1840 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d93a3effd0005
[junit4:junit4]   2> 4172 T1874 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 4172 T1837 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:20635 which had sessionid 0x13d93a3effd0005
[junit4:junit4]   2> 4172 T1835 oaz.ZooKeeper.close Session: 0x13d93a3effd0005 closed
[junit4:junit4]   2> 4172 T1835 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 4185 T1835 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13523/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@2c58d65a
[junit4:junit4]   2> 4187 T1875 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13523. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 4187 T1835 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4188 T1837 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:32163
[junit4:junit4]   2> 4188 T1875 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13523, initiating session
[junit4:junit4]   2> 4189 T1837 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:32163
[junit4:junit4]   2> 4190 T1839 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d93a3effd0006 with negotiated timeout 20000 for client /140.211.11.196:32163
[junit4:junit4]   2> 4190 T1875 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13523, sessionid = 0x13d93a3effd0006, negotiated timeout = 20000
[junit4:junit4]   2> 4190 T1876 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2c58d65a name:ZooKeeperConnection Watcher:127.0.0.1:13523/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4190 T1835 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4191 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0006 type:create cxid:0x1 zxid:0x48 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4193 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0006 type:create cxid:0x3 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4201 T1835 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4228 T596 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 5204 T1835 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:20515_
[junit4:junit4]   2> 5205 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0006 type:delete cxid:0xd zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:20515_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:20515_
[junit4:junit4]   2> 5206 T1835 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:20515_
[junit4:junit4]   2> 5209 T1876 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5209 T1863 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5209 T1857 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5210 T1857 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 5227 T1877 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363981631223/collection1
[junit4:junit4]   2> 5227 T1877 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 5228 T1877 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 5228 T1877 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 5229 T1877 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363981631223/collection1/'
[junit4:junit4]   2> 5231 T1877 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty1-1363981631223/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 5231 T1877 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty1-1363981631223/collection1/lib/README' to classloader
[junit4:junit4]   2> 5297 T1858 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5297 T1877 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 5298 T1858 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"1",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:40996_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:40996"}
[junit4:junit4]   2> 5311 T1876 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 5311 T1857 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 5311 T1863 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 5358 T1877 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 5459 T1877 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 5465 T1877 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 6113 T1877 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 6126 T1877 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 6130 T1877 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 6145 T1877 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6150 T1877 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6154 T1877 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6155 T1877 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 6156 T1877 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 6156 T1877 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6157 T1877 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 6157 T1877 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 6158 T1877 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 6158 T1877 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363981631223/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty1/
[junit4:junit4]   2> 6158 T1877 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4bf4e4c0
[junit4:junit4]   2> 6159 T1877 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 6160 T1877 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty1 forceNew: false
[junit4:junit4]   2> 6160 T1877 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty1/index/
[junit4:junit4]   2> 6160 T1877 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 6160 T1877 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty1/index forceNew: false
[junit4:junit4]   2> 6163 T1877 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69e19dfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@158960a4),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 6164 T1877 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 6167 T1877 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 6167 T1877 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 6168 T1877 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 6169 T1877 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 6169 T1877 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 6169 T1877 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 6170 T1877 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 6170 T1877 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 6171 T1877 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 6184 T1877 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 6190 T1877 oass.SolrIndexSearcher.<init> Opening Searcher@1cf07f83 main
[junit4:junit4]   2> 6190 T1877 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty1/tlog
[junit4:junit4]   2> 6191 T1877 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 6191 T1877 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 6196 T1878 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1cf07f83 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 6199 T1877 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 6199 T1877 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 6815 T1858 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6816 T1858 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"2",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:20515_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:20515"}
[junit4:junit4]   2> 6816 T1858 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4:junit4]   2> 6817 T1858 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 6836 T1857 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 6836 T1863 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 6836 T1876 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 7202 T1877 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 7202 T1877 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:20515 collection:collection1 shard:shard1
[junit4:junit4]   2> 7203 T1877 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 7221 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0006 type:delete cxid:0x4a zxid:0x5a txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 7221 T1877 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 7222 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0006 type:create cxid:0x4b zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7231 T1877 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 7231 T1877 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 7232 T1877 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:20515/collection1/
[junit4:junit4]   2> 7232 T1877 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 7232 T1877 oasc.SyncStrategy.syncToMe http://127.0.0.1:20515/collection1/ has no replicas
[junit4:junit4]   2> 7232 T1877 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:20515/collection1/
[junit4:junit4]   2> 7233 T1877 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 7236 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0006 type:create cxid:0x56 zxid:0x5f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8342 T1858 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8366 T1857 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 8366 T1863 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 8366 T1876 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 8411 T1877 oasc.ZkController.register We are http://127.0.0.1:20515/collection1/ and leader is http://127.0.0.1:20515/collection1/
[junit4:junit4]   2> 8411 T1877 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:20515
[junit4:junit4]   2> 8411 T1877 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 8411 T1877 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 8412 T1877 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 8413 T1877 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8414 T1835 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0
[junit4:junit4]   2> 8415 T1835 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 8416 T1835 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 8656 T1835 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 8660 T1835 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:53253
[junit4:junit4]   2> 8661 T1835 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 8662 T1835 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8662 T1835 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363981635810
[junit4:junit4]   2> 8663 T1835 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363981635810/solr.xml
[junit4:junit4]   2> 8663 T1835 oasc.CoreContainer.<init> New CoreContainer 205431069
[junit4:junit4]   2> 8664 T1835 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363981635810/'
[junit4:junit4]   2> 8664 T1835 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363981635810/'
[junit4:junit4]   2> 8739 T1835 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 8739 T1835 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 8740 T1835 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 8741 T1835 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 8741 T1835 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 8742 T1835 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 8742 T1835 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 8743 T1835 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 8743 T1835 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 8744 T1835 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 8770 T1835 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 8794 T1835 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:13523/solr
[junit4:junit4]   2> 8795 T1835 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 8795 T1835 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13523 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@5fd07764
[junit4:junit4]   2> 8797 T1835 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8797 T1888 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13523. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 8798 T1888 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13523, initiating session
[junit4:junit4]   2> 8799 T1837 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:60401
[junit4:junit4]   2> 8799 T1837 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:60401
[junit4:junit4]   2> 8802 T1839 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d93a3effd0007 with negotiated timeout 20000 for client /140.211.11.196:60401
[junit4:junit4]   2> 8802 T1888 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13523, sessionid = 0x13d93a3effd0007, negotiated timeout = 20000
[junit4:junit4]   2> 8802 T1889 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5fd07764 name:ZooKeeperConnection Watcher:127.0.0.1:13523 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8802 T1835 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8803 T1840 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d93a3effd0007
[junit4:junit4]   2> 8818 T1889 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 8818 T1837 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:60401 which had sessionid 0x13d93a3effd0007
[junit4:junit4]   2> 8818 T1835 oaz.ZooKeeper.close Session: 0x13d93a3effd0007 closed
[junit4:junit4]   2> 8818 T1835 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 8830 T1835 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13523/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@3600fb22
[junit4:junit4]   2> 8831 T1835 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8832 T1890 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13523. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 8832 T1890 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13523, initiating session
[junit4:junit4]   2> 8832 T1837 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:12058
[junit4:junit4]   2> 8833 T1837 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:12058
[junit4:junit4]   2> 8835 T1839 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d93a3effd0008 with negotiated timeout 20000 for client /140.211.11.196:12058
[junit4:junit4]   2> 8835 T1890 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13523, sessionid = 0x13d93a3effd0008, negotiated timeout = 20000
[junit4:junit4]   2> 8835 T1891 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3600fb22 name:ZooKeeperConnection Watcher:127.0.0.1:13523/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8835 T1835 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8836 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0008 type:create cxid:0x1 zxid:0x6c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8842 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0008 type:create cxid:0x3 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8844 T1835 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 8889 T606 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 9847 T1835 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53253_
[junit4:junit4]   2> 9848 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd0008 type:delete cxid:0xd zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:53253_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:53253_
[junit4:junit4]   2> 9860 T1835 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53253_
[junit4:junit4]   2> 9862 T1876 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 9862 T1857 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9862 T1863 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9863 T1857 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9862 T1891 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9863 T1863 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9863 T1876 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9881 T1858 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9882 T1858 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"2",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:20515_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:20515"}
[junit4:junit4]   2> 9887 T1892 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363981635810/collection1
[junit4:junit4]   2> 9887 T1892 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 9895 T1891 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9895 T1857 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9895 T1892 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 9895 T1876 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9895 T1863 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9895 T1892 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 9898 T1892 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363981635810/collection1/'
[junit4:junit4]   2> 9899 T1892 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty2-1363981635810/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 9899 T1892 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty2-1363981635810/collection1/lib/README' to classloader
[junit4:junit4]   2> 9952 T1892 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 10012 T1892 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 10113 T1892 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 10119 T1892 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 10620 T614 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 10728 T1892 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 10736 T1892 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 10739 T1892 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 10750 T1892 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10754 T1892 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10757 T1892 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10758 T1892 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 10758 T1892 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 10758 T1892 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10759 T1892 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 10759 T1892 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 10759 T1892 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 10759 T1892 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363981635810/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty2/
[junit4:junit4]   2> 10759 T1892 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4bf4e4c0
[junit4:junit4]   2> 10760 T1892 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 10761 T1892 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty2 forceNew: false
[junit4:junit4]   2> 10761 T1892 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty2/index/
[junit4:junit4]   2> 10761 T1892 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 10761 T1892 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty2/index forceNew: false
[junit4:junit4]   2> 10763 T1892 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@19c5437a lockFactory=org.apache.lucene.store.NativeFSLockFactory@713b17d8),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10763 T1892 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 10766 T1892 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 10766 T1892 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 10766 T1892 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 10767 T1892 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 10767 T1892 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 10767 T1892 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 10768 T1892 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 10768 T1892 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 10768 T1892 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 10777 T1892 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 10781 T1892 oass.SolrIndexSearcher.<init> Opening Searcher@745ce7d9 main
[junit4:junit4]   2> 10781 T1892 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty2/tlog
[junit4:junit4]   2> 10782 T1892 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 10782 T1892 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 10786 T1893 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@745ce7d9 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 10788 T1892 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 10788 T1892 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 11399 T1858 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11400 T1858 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"3",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53253_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53253"}
[junit4:junit4]   2> 11400 T1858 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4]   2> 11400 T1858 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 11467 T1857 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 11467 T1863 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 11467 T1876 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 11467 T1891 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 11790 T1892 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 11790 T1892 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53253 collection:collection1 shard:shard1
[junit4:junit4]   2> 11793 T1892 oasc.ZkController.register We are http://127.0.0.1:53253/collection1/ and leader is http://127.0.0.1:20515/collection1/
[junit4:junit4]   2> 11794 T1892 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53253
[junit4:junit4]   2> 11794 T1892 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 11794 T1892 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C68 name=collection1 org.apache.solr.core.SolrCore@1bf8e628 url=http://127.0.0.1:53253/collection1 node=127.0.0.1:53253_ C68_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:53253_, base_url=http://127.0.0.1:53253}
[junit4:junit4]   2> 11796 T1894 C68 P53253 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 11796 T1892 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11796 T1894 C68 P53253 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 11797 T1894 C68 P53253 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 11797 T1894 C68 P53253 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 11797 T1835 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0
[junit4:junit4]   2> 11798 T1835 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 11798 T1835 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 11803 T1894 C68 P53253 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 11997 T1835 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 12000 T1835 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:54989
[junit4:junit4]   2> 12001 T1835 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 12002 T1835 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 12002 T1835 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1363981639188
[junit4:junit4]   2> 12003 T1835 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1363981639188/solr.xml
[junit4:junit4]   2> 12003 T1835 oasc.CoreContainer.<init> New CoreContainer 1046647287
[junit4:junit4]   2> 12004 T1835 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1363981639188/'
[junit4:junit4]   2> 12004 T1835 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1363981639188/'
[junit4:junit4]   2> 12065 T1835 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 12066 T1835 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 12066 T1835 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 12067 T1835 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 12067 T1835 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 12068 T1835 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 12068 T1835 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 12069 T1835 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 12069 T1835 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 12070 T1835 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 12090 T1835 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 12109 T1835 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:13523/solr
[junit4:junit4]   2> 12110 T1835 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 12110 T1835 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13523 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@776190c3
[junit4:junit4]   2> 12112 T1835 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12112 T1904 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13523. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 12113 T1904 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13523, initiating session
[junit4:junit4]   2> 12113 T1837 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:26098
[junit4:junit4]   2> 12113 T1837 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:26098
[junit4:junit4]   2> 12141 T1839 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d93a3effd0009 with negotiated timeout 20000 for client /140.211.11.196:26098
[junit4:junit4]   2> 12141 T1904 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13523, sessionid = 0x13d93a3effd0009, negotiated timeout = 20000
[junit4:junit4]   2> 12142 T1905 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@776190c3 name:ZooKeeperConnection Watcher:127.0.0.1:13523 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12142 T1835 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12143 T1840 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d93a3effd0009
[junit4:junit4]   2> 12144 T1905 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 12144 T1837 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:26098 which had sessionid 0x13d93a3effd0009
[junit4:junit4]   2> 12144 T1835 oaz.ZooKeeper.close Session: 0x13d93a3effd0009 closed
[junit4:junit4]   2> 12145 T1835 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 12154 T1835 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13523/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@416c2849
[junit4:junit4]   2> 12155 T1835 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12156 T1906 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13523. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 12156 T1906 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13523, initiating session
[junit4:junit4]   2> 12157 T1837 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:37995
[junit4:junit4]   2> 12157 T1837 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:37995
[junit4:junit4]   2> 12158 T1839 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d93a3effd000a with negotiated timeout 20000 for client /140.211.11.196:37995
[junit4:junit4]   2> 12158 T1906 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13523, sessionid = 0x13d93a3effd000a, negotiated timeout = 20000
[junit4:junit4]   2> 12158 T1907 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@416c2849 name:ZooKeeperConnection Watcher:127.0.0.1:13523/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12159 T1835 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12159 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd000a type:create cxid:0x1 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12161 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd000a type:create cxid:0x3 zxid:0x80 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12170 T1835 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 12353 T622 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 13009 T1858 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13010 T1858 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"3",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53253_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53253"}
[junit4:junit4]   2> 13058 T1863 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 13058 T1876 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 13058 T1891 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 13058 T1907 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 13058 T1857 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 13173 T1835 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54989_
[junit4:junit4]   2> 13174 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd000a type:delete cxid:0xf zxid:0x85 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:54989_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:54989_
[junit4:junit4]   2> 13175 T1835 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54989_
[junit4:junit4]   2> 13177 T1907 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 13177 T1876 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 13177 T1891 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13177 T1863 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13178 T1891 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 13178 T1863 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 13178 T1857 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13178 T1857 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 13179 T1876 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13179 T1907 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13193 T1908 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1363981639188/collection1
[junit4:junit4]   2> 13193 T1908 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 13193 T1908 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 13194 T1908 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 13195 T1908 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1363981639188/collection1/'
[junit4:junit4]   2> 13196 T1908 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty3-1363981639188/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 13197 T1908 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty3-1363981639188/collection1/lib/README' to classloader
[junit4:junit4]   2> 13247 T1908 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 13307 T1908 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 13408 T1908 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 13414 T1908 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 13816 T1866 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {coreNodeName=3&state=recovering&nodeName=127.0.0.1:53253_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2002 
[junit4:junit4]   2> 13985 T630 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 14045 T1908 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 14057 T1908 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 14061 T1908 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 14075 T1908 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14080 T1908 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14084 T1908 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14085 T1908 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 14086 T1908 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 14086 T1908 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14087 T1908 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 14087 T1908 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 14087 T1908 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 14088 T1908 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1363981639188/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty3/
[junit4:junit4]   2> 14088 T1908 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4bf4e4c0
[junit4:junit4]   2> 14088 T1908 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 14089 T1908 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty3 forceNew: false
[junit4:junit4]   2> 14089 T1908 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty3/index/
[junit4:junit4]   2> 14090 T1908 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 14090 T1908 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty3/index forceNew: false
[junit4:junit4]   2> 14093 T1908 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c2ade30 lockFactory=org.apache.lucene.store.NativeFSLockFactory@173728a7),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 14093 T1908 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 14096 T1908 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 14097 T1908 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 14097 T1908 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 14098 T1908 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 14099 T1908 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 14099 T1908 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 14099 T1908 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 14100 T1908 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 14101 T1908 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 14113 T1908 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 14119 T1908 oass.SolrIndexSearcher.<init> Opening Searcher@37ee9554 main
[junit4:junit4]   2> 14120 T1908 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty3/tlog
[junit4:junit4]   2> 14120 T1908 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 14121 T1908 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 14126 T1909 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@37ee9554 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 14128 T1908 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 14128 T1908 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 14562 T1858 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14563 T1858 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"4",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54989_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54989"}
[junit4:junit4]   2> 14563 T1858 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4]   2> 14563 T1858 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 14577 T1891 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 14577 T1907 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 14577 T1857 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 14577 T1876 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 14577 T1863 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 15131 T1908 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 15131 T1908 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54989 collection:collection1 shard:shard1
[junit4:junit4]   2> 15134 T1908 oasc.ZkController.register We are http://127.0.0.1:54989/collection1/ and leader is http://127.0.0.1:20515/collection1/
[junit4:junit4]   2> 15134 T1908 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54989
[junit4:junit4]   2> 15134 T1908 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 15134 T1908 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C69 name=collection1 org.apache.solr.core.SolrCore@4228abeb url=http://127.0.0.1:54989/collection1 node=127.0.0.1:54989_ C69_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:54989_, base_url=http://127.0.0.1:54989}
[junit4:junit4]   2> 15136 T1910 C69 P54989 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 15136 T1908 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15136 T1910 C69 P54989 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 15137 T1910 C69 P54989 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 15137 T1910 C69 P54989 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 15137 T1835 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0
[junit4:junit4]   2> 15138 T1835 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 15138 T1910 C69 P54989 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 15138 T1835 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 15344 T1835 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 15347 T1835 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:17812
[junit4:junit4]   2> 15348 T1835 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 15348 T1835 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 15349 T1835 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty4-1363981642529
[junit4:junit4]   2> 15349 T1835 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty4-1363981642529/solr.xml
[junit4:junit4]   2> 15350 T1835 oasc.CoreContainer.<init> New CoreContainer 590818220
[junit4:junit4]   2> 15350 T1835 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty4-1363981642529/'
[junit4:junit4]   2> 15351 T1835 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty4-1363981642529/'
[junit4:junit4]   2> 15412 T1835 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 15413 T1835 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 15414 T1835 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 15414 T1835 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 15414 T1835 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 15415 T1835 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 15415 T1835 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 15416 T1835 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 15416 T1835 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 15417 T1835 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 15439 T1835 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 15458 T1835 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:13523/solr
[junit4:junit4]   2> 15459 T1835 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 15460 T1835 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13523 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@51ae498d
[junit4:junit4]   2> 15461 T1835 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 15461 T1920 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13523. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 15462 T1920 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13523, initiating session
[junit4:junit4]   2> 15462 T1837 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:32786
[junit4:junit4]   2> 15462 T1837 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:32786
[junit4:junit4]   2> 15464 T1839 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d93a3effd000b with negotiated timeout 20000 for client /140.211.11.196:32786
[junit4:junit4]   2> 15464 T1920 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13523, sessionid = 0x13d93a3effd000b, negotiated timeout = 20000
[junit4:junit4]   2> 15465 T1921 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51ae498d name:ZooKeeperConnection Watcher:127.0.0.1:13523 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 15465 T1835 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 15466 T1840 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d93a3effd000b
[junit4:junit4]   2> 15482 T1921 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 15482 T1837 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:32786 which had sessionid 0x13d93a3effd000b
[junit4:junit4]   2> 15482 T1835 oaz.ZooKeeper.close Session: 0x13d93a3effd000b closed
[junit4:junit4]   2> 15482 T1835 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 15494 T1835 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:13523/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@69988734
[junit4:junit4]   2> 15495 T1835 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 15495 T1922 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:13523. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 15496 T1922 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:13523, initiating session
[junit4:junit4]   2> 15496 T1837 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:43663
[junit4:junit4]   2> 15496 T1837 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:43663
[junit4:junit4]   2> 15498 T1839 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d93a3effd000c with negotiated timeout 20000 for client /140.211.11.196:43663
[junit4:junit4]   2> 15498 T1922 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:13523, sessionid = 0x13d93a3effd000c, negotiated timeout = 20000
[junit4:junit4]   2> 15498 T1923 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@69988734 name:ZooKeeperConnection Watcher:127.0.0.1:13523/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 15498 T1835 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 15499 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd000c type:create cxid:0x1 zxid:0x92 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 15501 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd000c type:create cxid:0x3 zxid:0x93 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 15509 T1835 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 15717 T638 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2>  C68_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:53253_, base_url=http://127.0.0.1:53253}
[junit4:junit4]   2> 15818 T1894 C68 P53253 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:20515/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 15818 T1894 C68 P53253 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:53253 START replicas=[http://127.0.0.1:20515/collection1/] nUpdates=100
[junit4:junit4]   2> 15819 T1894 C68 P53253 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 15819 T1894 C68 P53253 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 15820 T1894 C68 P53253 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 15820 T1894 C68 P53253 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 15820 T1894 C68 P53253 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 15820 T1894 C68 P53253 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:20515/collection1/. core=collection1
[junit4:junit4]   2> 15820 T1894 C68 P53253 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C70 name=collection1 org.apache.solr.core.SolrCore@254789c1 url=http://127.0.0.1:20515/collection1 node=127.0.0.1:20515_ C70_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:20515_, base_url=http://127.0.0.1:20515, leader=true}
[junit4:junit4]   2> 15827 T1868 C70 P20515 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15834 T1869 C70 P20515 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 15836 T1869 C70 P20515 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69e19dfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@158960a4),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 15837 T1869 C70 P20515 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 15837 T1869 C70 P20515 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69e19dfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@158960a4),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69e19dfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@158960a4),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 15838 T1869 C70 P20515 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 15838 T1869 C70 P20515 oass.SolrIndexSearcher.<init> Opening Searcher@2bfc4165 realtime
[junit4:junit4]   2> 15839 T1869 C70 P20515 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15839 T1869 C70 P20515 /update {waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 6
[junit4:junit4]   2> 15840 T1894 C68 P53253 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 15840 T1894 C68 P53253 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 15842 T1870 C70 P20515 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 15843 T1870 C70 P20515 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15843 T1894 C68 P53253 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 15843 T1894 C68 P53253 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 15844 T1894 C68 P53253 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 15846 T1870 C70 P20515 REQ /replication {command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15847 T1894 C68 P53253 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 15849 T1894 C68 P53253 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty2/index.20130322174723222 forceNew: false
[junit4:junit4]   2> 15849 T1894 C68 P53253 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@3027ef39 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2cb620db) fullCopy=false
[junit4:junit4]   2> 15852 T1870 C70 P20515 REQ /replication {file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
[junit4:junit4]   2> 15854 T1894 C68 P53253 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 15855 T1894 C68 P53253 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 15855 T1894 C68 P53253 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 15857 T1894 C68 P53253 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@19c5437a lockFactory=org.apache.lucene.store.NativeFSLockFactory@713b17d8),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@19c5437a lockFactory=org.apache.lucene.store.NativeFSLockFactory@713b17d8),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 15857 T1894 C68 P53253 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 15857 T1894 C68 P53253 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 15858 T1894 C68 P53253 oass.SolrIndexSearcher.<init> Opening Searcher@52df42e2 main
[junit4:junit4]   2> 15859 T1893 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@52df42e2 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 15860 T1894 C68 P53253 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 15860 T1894 C68 P53253 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 15860 T1894 C68 P53253 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 15860 T1894 C68 P53253 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 15873 T1894 C68 P53253 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 16081 T1858 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16082 T1858 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"4",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54989_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54989"}
[junit4:junit4]   2> 16085 T1858 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"3",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53253_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53253"}
[junit4:junit4]   2> 16105 T1863 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 16105 T1857 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 16105 T1923 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 16105 T1907 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 16105 T1891 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 16105 T1876 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 16157 T1867 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {coreNodeName=4&state=recovering&nodeName=127.0.0.1:54989_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1001 
[junit4:junit4]   2> 16512 T1835 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:17812_
[junit4:junit4]   2> 16513 T1840 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d93a3effd000c type:delete cxid:0xf zxid:0x9c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:17812_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:17812_
[junit4:junit4]   2> 16552 T1835 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:17812_
[junit4:junit4]   2> 16582 T1923 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 16582 T1907 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 16583 T1857 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 16583 T1891 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 16582 T1876 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 16583 T1857 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 16583 T1891 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 16583 T1863 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 16584 T1863 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 16585 T1923 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 16585 T1876 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 16585 T1907 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 16591 T1926 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty4-1363981642529/collection1
[junit4:junit4]   2> 16591 T1926 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 16592 T1926 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 16592 T1926 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 16593 T1926 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty4-1363981642529/collection1/'
[junit4:junit4]   2> 16595 T1926 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty4-1363981642529/collection1/lib/README' to classloader
[junit4:junit4]   2> 16595 T1926 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty4-1363981642529/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 16648 T1926 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 16707 T1926 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 16808 T1926 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 16814 T1926 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 17351 T646 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 17441 T1926 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 17453 T1926 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 17457 T1926 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 17471 T1926 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 17476 T1926 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 17481 T1926 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 17482 T1926 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 17482 T1926 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 17482 T1926 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 17483 T1926 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 17483 T1926 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 17483 T1926 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 17484 T1926 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty4-1363981642529/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty4/
[junit4:junit4]   2> 17484 T1926 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4bf4e4c0
[junit4:junit4]   2> 17485 T1926 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 17486 T1926 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty4 forceNew: false
[junit4:junit4]   2> 17486 T1926 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty4/index/
[junit4:junit4]   2> 17486 T1926 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 17486 T1926 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty4/index forceNew: false
[junit4:junit4]   2> 17489 T1926 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@140ecfa6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@32e36fb5),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 17490 T1926 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 17493 T1926 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 17493 T1926 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 17494 T1926 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 17495 T1926 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 17495 T1926 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 17496 T1926 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 17496 T1926 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 17497 T1926 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 17497 T1926 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 17510 T1926 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 17516 T1926 oass.SolrIndexSearcher.<init> Opening Searcher@2d7db15e main
[junit4:junit4]   2> 17517 T1926 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty4/tlog
[junit4:junit4]   2> 17518 T1926 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 17518 T1926 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 17524 T1927 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2d7db15e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 17526 T1926 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 17527 T1926 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 17611 T1858 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 17612 T1858 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"5",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:17812_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:17812"}
[junit4:junit4]   2> 17612 T1858 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4]   2> 17612 T1858 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 17626 T1857 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 17626 T1863 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 17626 T1923 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 17626 T1907 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 17626 T1891 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 17626 T1876 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2>  C69_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:54989_, base_url=http://127.0.0.1:54989}
[junit4:junit4]   2> 18158 T1910 C69 P54989 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:20515/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 18158 T1910 C69 P54989 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:54989 START replicas=[http://127.0.0.1:20515/collection1/] nUpdates=100
[junit4:junit4]   2> 18159 T1910 C69 P54989 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 18159 T1910 C69 P54989 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 18159 T1910 C69 P54989 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 18159 T1910 C69 P54989 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 18159 T1910 C69 P54989 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 18160 T1910 C69 P54989 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:20515/collection1/. core=collection1
[junit4:junit4]   2> 18160 T1910 C69 P54989 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 18161 T1868 C70 P20515 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0 
[junit4:junit4]   2> 18175 T1871 C70 P20515 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 18177 T1871 C70 P20515 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69e19dfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@158960a4),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69e19dfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@158960a4),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   2> 18177 T1871 C70 P20515 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[segments_3]
[junit4:junit4]   2> 18178 T1871 C70 P20515 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18178 T1871 C70 P20515 /update {waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 3
[junit4:junit4]   2> 18179 T1910 C69 P54989 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 18180 T1910 C69 P54989 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 18182 T1870 C70 P20515 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 18183 T1910 C69 P54989 oash.SnapPuller.fetchLatestIndex Master's generation: 3
[junit4:junit4]   2> 18183 T1910 C69 P54989 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 18183 T1910 C69 P54989 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 18186 T1870 C70 P20515 REQ /replication {command=filelist&qt=/replication&wt=javabin&generation=3&version=2} status=0 QTime=0 
[junit4:junit4]   2> 18187 T1910 C69 P54989 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 18189 T1910 C69 P54989 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty3/index.20130322174725562 forceNew: false
[junit4:junit4]   2> 18189 T1910 C69 P54989 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@3a59876f lockFactory=org.apache.lucene.store.NativeFSLockFactory@39524175) fullCopy=false
[junit4:junit4]   2> 18192 T1870 C70 P20515 REQ /replication {file=segments_3&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0 
[junit4:junit4]   2> 18193 T1910 C69 P54989 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 18194 T1910 C69 P54989 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 18195 T1910 C69 P54989 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 18196 T1910 C69 P54989 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c2ade30 lockFactory=org.apache.lucene.store.NativeFSLockFactory@173728a7),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c2ade30 lockFactory=org.apache.lucene.store.NativeFSLockFactory@173728a7),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   2> 18197 T1910 C69 P54989 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[segments_3]
[junit4:junit4]   2> 18197 T1910 C69 P54989 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 18197 T1910 C69 P54989 oass.SolrIndexSearcher.<init> Opening Searcher@39ee3f34 main
[junit4:junit4]   2> 18199 T1909 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@39ee3f34 main{StandardDirectoryReader(segments_3:1:nrt)}
[junit4:junit4]   2> 18199 T1910 C69 P54989 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 18199 T1910 C69 P54989 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 18200 T1910 C69 P54989 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 18200 T1910 C69 P54989 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 18222 T1910 C69 P54989 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 18536 T1926 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 18536 T1926 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:17812 collection:collection1 shard:shard1
[junit4:junit4]   2> 18539 T1926 oasc.ZkController.register We are http://127.0.0.1:17812/collection1/ and leader is http://127.0.0.1:20515/collection1/
[junit4:junit4]   2> 18539 T1926 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:17812
[junit4:junit4]   2> 18539 T1926 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 18539 T1926 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C71 name=collection1 org.apache.solr.core.SolrCore@54db1190 url=http://127.0.0.1:17812/collection1 node=127.0.0.1:17812_ C71_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:17812_, base_url=http://127.0.0.1:17812}
[junit4:junit4]   2> 18540 T1930 C71 P17812 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 18540 T1926 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18541 T1930 C71 P17812 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 18541 T1930 C71 P17812 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 18541 T1930 C71 P17812 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 18541 T1835 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build/solr-core/test/J0
[junit4:junit4]   2> 18542 T1835 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 18542 T1930 C71 P17812 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 18543 T1835 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 18554 T1835 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18555 T1835 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt
[junit4:junit4]   2> 18556 T1835 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4:junit4]   2> 18556 T1835 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19057 T654 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 19130 T1858 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19131 T1858 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"4",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54989_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54989"}
[junit4:junit4]   2> 19143 T1858 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"5",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:17812_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:17812"}
[junit4:junit4]   2> 19158 T1923 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 19158 T1857 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 19158 T1863 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 19158 T1907 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 19158 T1891 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 19158 T1876 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 19556 T1872 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {coreNodeName=5&state=recovering&nodeName=127.0.0.1:17812_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1001 
[junit4:junit4]   2> 19558 T1835 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20560 T1835 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20789 T662 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2>  C71_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:17812_, base_url=http://127.0.0.1:17812}
[junit4:junit4]   2> 21558 T1930 C71 P17812 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:20515/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 21558 T1930 C71 P17812 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:17812 START replicas=[http://127.0.0.1:20515/collection1/] nUpdates=100
[junit4:junit4]   2> 21559 T1930 C71 P17812 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 21559 T1930 C71 P17812 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 21559 T1930 C71 P17812 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 21559 T1930 C71 P17812 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 21559 T1930 C71 P17812 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 21559 T1930 C71 P17812 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:20515/collection1/. core=collection1
[junit4:junit4]   2> 21560 T1930 C71 P17812 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 21562 T1868 C70 P20515 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21562 T1835 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 21572 T1866 C70 P20515 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 21573 T1866 C70 P20515 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=3
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69e19dfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@158960a4),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69e19dfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@158960a4),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69e19dfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@158960a4),segFN=segments_4,generation=4,filenames=[segments_4]
[junit4:junit4]   2> 21573 T1866 C70 P20515 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[segments_4]
[junit4:junit4]   2> 21574 T1866 C70 P20515 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 21574 T1866 C70 P20515 /update {waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 2
[junit4:junit4]   2> 21575 T1930 C71 P17812 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 21575 T1930 C71 P17812 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 21578 T1870 C70 P20515 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 21579 T1930 C71 P17812 oash.SnapPuller.fetchLatestIndex Master's generation: 4
[junit4:junit4]   2> 21579 T1930 C71 P17812 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 21580 T1930 C71 P17812 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 21582 T1870 C70 P20515 REQ /replication {command=filelist&qt=/replication&wt=javabin&generation=4&version=2} status=0 QTime=0 
[junit4:junit4]   2> 21583 T1930 C71 P17812 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 21585 T1930 C71 P17812 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty4/index.20130322174728958 forceNew: false
[junit4:junit4]   2> 21585 T1930 C71 P17812 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@144ebf08 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d29810f) fullCopy=false
[junit4:junit4]   2> 21587 T1870 C70 P20515 REQ /replication {file=segments_4&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0 
[junit4:junit4]   2> 21588 T1930 C71 P17812 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 21589 T1930 C71 P17812 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 21590 T1930 C71 P17812 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 21591 T1930 C71 P17812 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@140ecfa6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@32e36fb5),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@140ecfa6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@32e36fb5),segFN=segments_4,generation=4,filenames=[segments_4]
[junit4:junit4]   2> 21592 T1930 C71 P17812 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[segments_4]
[junit4:junit4]   2> 21592 T1930 C71 P17812 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 21592 T1930 C71 P17812 oass.SolrIndexSearcher.<init> Opening Searcher@63c3bce2 main
[junit4:junit4]   2> 21594 T1927 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@63c3bce2 main{StandardDirectoryReader(segments_4:1:nrt)}
[junit4:junit4]   2> 21594 T1930 C71 P17812 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 21594 T1930 C71 P17812 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 21594 T1930 C71 P17812 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 21595 T1930 C71 P17812 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 21597 T1930 C71 P17812 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 22173 T1858 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22174 T1858 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"5",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:17812_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:17812"}
[junit4:junit4]   2> 22216 T1923 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 22216 T1863 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 22216 T1907 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 22216 T1876 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 22216 T1891 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 22216 T1857 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 22430 T668 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 22564 T1835 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22565 T1835 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4]   2> ASYNC  NEW_CORE C72 name=collection1 org.apache.solr.core.SolrCore@35d38d34 url=http://127.0.0.1:40996/collection1 node=127.0.0.1:40996_ C72_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:40996_, base_url=http://127.0.0.1:40996, leader=true}
[junit4:junit4]   2> 22573 T1847 C72 P40996 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 22576 T1847 C72 P40996 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3e85c16e lockFactory=org.apache.lucene.store.NativeFSLockFactory@1236e6f9),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 22576 T1847 C72 P40996 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 22578 T1847 C72 P40996 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3e85c16e lockFactory=org.apache.lucene.store.NativeFSLockFactory@1236e6f9),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3e85c16e lockFactory=org.apache.lucene.store.NativeFSLockFactory@1236e6f9),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 22578 T1847 C72 P40996 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 22579 T1847 C72 P40996 oass.SolrIndexSearcher.<init> Opening Searcher@4d6b9f6f main
[junit4:junit4]   2> 22579 T1847 C72 P40996 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 22580 T1861 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4d6b9f6f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 22583 T1847 C72 P40996 /update {waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 11
[junit4:junit4]   2> 22594 T1869 C70 P20515 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 22595 T1869 C70 P20515 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=4
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69e19dfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@158960a4),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69e19dfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@158960a4),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69e19dfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@158960a4),segFN=segments_4,generation=4,filenames=[segments_4]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69e19dfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@158960a4),segFN=segments_5,generation=5,filenames=[segments_5]
[junit4:junit4]   2> 22595 T1869 C70 P20515 oasc.SolrDeletionPolicy.updateCommits newest commit = 5[segments_5]
[junit4:junit4]   2> 22596 T1869 C70 P20515 oass.SolrIndexSearcher.<init> Opening Searcher@363ceed7 main
[junit4:junit4]   2> 22596 T1869 C70 P20515 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 22597 T1878 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@363ceed7 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 22598 T1869 C70 P20515 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:53253/collection1/, StdNode: http://127.0.0.1:54989/collection1/, StdNode: http://127.0.0.1:17812/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4]   2>  C68_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:53253_, base_url=http://127.0.0.1:53253}
[junit4:junit4]   2> 22607 T1881 C68 P53253 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2>  C71_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:17812_, base_url=http://127.0.0.1:17812}
[junit4:junit4]   2> 22607 T1913 C71 P17812 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2>  C69_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:54989_, base_url=http://127.0.0.1:54989}
[junit4:junit4]   2> 22607 T1897 C69 P54989 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 22609 T1881 C68 P53253 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@19c5437a lockFactory=org.apache.lucene.store.NativeFSLockFactory@713b17d8),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@19c5437a lockFactory=org.apache.lucene.store.NativeFSLockFactory@713b17d8),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   2> 22610 T1897 C69 P54989 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c2ade30 lockFactory=org.apache.lucene.store.NativeFSLockFactory@173728a7),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c2ade30 lockFactory=org.apache.lucene.store.NativeFSLockFactory@173728a7),segFN=segments_4,generation=4,filenames=[segments_4]
[junit4:junit4]   2> 22610 T1913 C71 P17812 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@140ecfa6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@32e36fb5),segFN=segments_4,generation=4,filenames=[segments_4]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@140ecfa6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@32e36fb5),segFN=segments_5,generation=5,filenames=[segments_5]
[junit4:junit4]   2> 22610 T1881 C68 P53253 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[segments_3]
[junit4:junit4]   2> 22611 T1913 C71 P17812 oasc.SolrDeletionPolicy.updateCommits newest commit = 5[segments_5]
[junit4:junit4]   2> 22611 T1897 C69 P54989 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[segments_4]
[junit4:junit4]   2> 22611 T1881 C68 P53253 oass.SolrIndexSearcher.<init> Opening Searcher@282ad05d main
[junit4:junit4]   2> 22611 T1913 C71 P17812 oass.SolrIndexSearcher.<init> Opening Searcher@2be3a2e5 main
[junit4:junit4]   2> 22612 T1897 C69 P54989 oass.SolrIndexSearcher.<init> Opening Searcher@1c4165e4 main
[junit4:junit4]   2> 22612 T1881 C68 P53253 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 22612 T1913 C71 P17812 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 22613 T1927 oasc.JmxMonitoredMap.put WARNING Failed to register info bean: searcher javax.management.InstanceAlreadyExistsException: solr/collection1:type=searcher,id=org.apache.solr.search.SolrIndexSearcher
[junit4:junit4]   2> 	at com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:437)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerWithRepository(DefaultMBeanServerInterceptor.java:1898)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:966)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324)
[junit4:junit4]   2> 	at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:513)
[junit4:junit4]   2> 	at org.apache.solr.core.JmxMonitoredMap.put(JmxMonitoredMap.java:140)
[junit4:junit4]   2> 	at org.apache.solr.core.JmxMonitoredMap.put(JmxMonitoredMap.java:51)
[junit4:junit4]   2> 	at org.apache.solr.search.SolrIndexSearcher.register(SolrIndexSearcher.java:239)
[junit4:junit4]   2> 	at org.apache.solr.core.SolrCore.registerSearcher(SolrCore.java:1766)
[junit4:junit4]   2> 	at org.apache.solr.core.SolrCore.access$000(SolrCore.java:129)
[junit4:junit4]   2> 	at org.apache.solr.core.SolrCore$7.call(SolrCore.java:1643)
[junit4:junit4]   2> 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4]   2> 	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4:junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4:junit4]   2> 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 
[junit4:junit4]   2> 22613 T1893 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@282ad05d main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 22612 T1897 C69 P54989 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 22613 T1909 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1c4165e4 main{StandardDirectoryReader(segments_3:1:nrt)}
[junit4:junit4]   2> 22614 T1881 C68 P53253 /update {waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 7
[junit4:junit4]   2> 22614 T1897 C69 P54989 /update {waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 7
[junit4:junit4]   2> 22614 T1927 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2be3a2e5 main{StandardDirectoryReader(segments_4:1:nrt)}
[junit4:junit4]   2> 22615 T1913 C71 P17812 /update {waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 8
[junit4:junit4]   2> 22616 T1869 C70 P20515 /update {waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 22
[junit4:junit4]   2> 22617 T1835 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22620 T1867 C70 P20515 REQ /select {tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 22622 T1882 C68 P53253 REQ /select {tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 22624 T1898 C69 P54989 REQ /select {tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 22626 T1914 C71 P17812 REQ /select {tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 24092 T676 oasc.OverseerCollectionProcessor.run WARNING Overseer cannot talk to ZK
[junit4:junit4]   2> 24632 T1847 C72 P40996 oass.SolrIndexSearcher.<init> Opening Searcher@bc1e54e realtime
[junit4:junit4]   2> 24633 T1847 C72 P40996 /update {wt=javabin&version=2} {deleteByQuery=*:* (-1430238424733843456)} 0 3
[junit4:junit4]   2> 24642 T1897 C69 P54989 /update {update.distrib=FROMLEADER&_version_=-1430238424739086336&update.from=http://127.0.0.1:20515/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1430238424739086336)} 0 2
[junit4:junit4]   2> 24642 T1913 C71 P17812 /update {update.distrib=FROMLEADER&_version_=-1430238424739086336&update.from=http://127.0.0.1:20515/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1430238424739086336)} 0 2
[junit4:junit4]   2> 24642 T1881 C68 P53253 /update {update.distrib=FROMLEADER&_version_=-1430238424739086336&update.from=http://127.0.0.1:20515/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1430238424739086336)} 0 2
[junit4:junit4]   2> 24643 T1869 C70 P20515 /update {wt=javabin&version=2} {deleteByQuery=*:* (-1430238424739086336)} 0 7
[junit4:junit4]   2> 24648 T1847 C72 P40996 /update {wt=javabin&version=2} {add=[0 (1430238424749572096)]} 0 2
[junit4:junit4]   2> 24657 T1913 C71 P17812 /update {distrib.from=http://127.0.0.1:20515/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[0 (1430238424755863552)]} 0 2
[junit4:junit4]   2> 24657 T1897 C69 P54989 /update {distrib.from=http://127.0.0.1:20515/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[0 (1430238424755863552)]} 0 2
[junit4:junit4]   2> 24657 T1881 C68 P53253 /update {distrib.from=http://127.0.0.1:20515/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[0 (1430238424755863552)]} 0 2
[junit4:junit4]   2> 24658 T1869 C70 P20515 /update {wt=javabin&version=2} {add=[0 (1430238424755863552)]} 0 7
[junit4:junit4]   2> 24662 T1847 C72 P40996 /update {wt=javabin&version=2} {add=[1 (1430238424765300736)]} 0 1
[junit4:junit4]   2> 24669 T1881 C68 P53253 /update {distrib.from=http://127.0.0.1:20515/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1430238424769495040)]} 0 1
[junit4:junit4]   2> 24669 T1913 C71 P17812 /update {distrib.from=http://127.0.0.1:20515/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1430238424769495040)]} 0 1
[junit4:junit4]   2> 24669 T1897 C69 P54989 /update {distrib.from=http://127.0.0.1:20515/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1430238424769495040)]} 0 1
[junit4:junit4]   2> 24670 T1869 C70 P20515 /update {wt=javabin&version=2} {add=[1 (1430238424769495040)]} 0 5
[junit4:junit4]   2> 24674 T1847 C72 P40996 /update {wt=javabin&version=2} {add=[2 (1430238424777883648)]} 0 1
[junit4:junit4]   2> 24681 T1897 C69 P54989 /update {distrib.from=http://127.0.0.1:20515/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[2 (1430238424782077952)]} 0 1
[junit4:junit4]   2> 24681 T1913 C71 P17812 /update {distrib.from=http://127.0.0.1:20515/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[2 (1430238424782077952)]} 0 1
[junit4:junit4]   2> 24682 T1869 C70 P20515 /update {test.distrib.skip.servers=http://127.0.0.1:53253/collection1/&wt=javabin&version=2} {add=[2 (1430238424782077952)]} 0 5
[junit4:junit4]   2> 24686 T1847 C72 P40996 /update {wt=javabin&version=2} {add=[3 (1430238424790466560)]} 0 1
[junit4:junit4]   2> 24693 T1913 C71 P17812 /update {distrib.from=http://127.0.0.1:20515/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[3 (1430238424794660864)]} 0 1
[junit4:junit4]   2> 24694 T1869 C70 P20515 /update {test.distrib.skip.servers=http://127.0.0.1:53253/collection1/&test.distrib.skip.servers=http://127.0.0.1:54989/collection1/&wt=javabin&version=2} {add=[3 (1430238424794660864)]} 0 5
[junit4:junit4]   2> 24697 T1847 C72 P40996 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 24711 T1847 C72 P40996 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3e85c16e lockFactory=org.apache.lucene.store.NativeFSLockFactory@1236e6f9),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3e85c16e lockFactory=org.apache.lucene.store.NativeFSLockFactory@1236e6f9),segFN=segments_3,generation=3,filenames=[_0.fnm, _0_TestBloomFilteredLucene41Postings_0.blm, _0_TestBloomFilteredLucene41Postings_0.tim, _0_Memory_0.ram, _0_Lucene41_0.pos, _0_TestBloomFilteredLucene41Postings_0.tip, _0.nvm, _0_TestBloomFilteredLucene41Postings_0.pos, _0_Memory_1.ram, _0_Lucene41_0.doc, _0.nvd, _0_TestBloomFilteredLucene41Postings_0.doc, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, segments_3]
[junit4:junit4]   2> 24711 T1847 C72 P40996 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0.fnm, _0_TestBloomFilteredLucene41Postings_0.blm, _0_TestBloomFilteredLucene41Postings_0.tim, _0_Memory_0.ram, _0_Lucene41_0.pos, _0_TestBloomFilteredLucene41Postings_0.tip, _0.nvm, _0_TestBloomFilteredLucene41Postings_0.pos, _0_Memory_1.ram, _0_Lucene41_0.doc, _0.nvd, _0_TestBloomFilteredLucene41Postings_0.doc, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, segments_3]
[junit4:junit4]   2> 24713 T1847 C72 P40996 oass.SolrIndexSearcher.<init> Opening Searcher@4a2fc535 main
[junit4:junit4]   2> 24714 T1847 C72 P40996 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 24714 T1861 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4a2fc535 main{StandardDirectoryReader(segments_3:3:nrt _0(4.2.1):C4)}
[junit4:junit4]   2> 24715 T1847 C72 P40996 /update {waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 18
[junit4:junit4]   2> 24718 T1869 C70 P20515 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 24725 T1869 C70 P20515 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=5
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69e19dfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@158960a4),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69e19dfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@158960a4),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69e19dfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@158960a4),segFN=segments_4,generation=4,filenames=[segments_4]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69e19dfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@158960a4),segFN=segments_5,generation=5,filenames=[segments_5]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@69e19dfc lockFactory=org.apache.lucene.store.NativeFSLockFactory@158960a4),segFN=segments_6,generation=6,filenames=[_0.fnm, _0_TestBloomFilteredLucene41Postings_0.blm, _0_TestBloomFilteredLucene41Postings_0.tim, _0_Memory_0.ram, _0_Lucene41_0.pos, _0_TestBloomFilteredLucene41Postings_0.tip, _0.nvm, _0_TestBloomFilteredLucene41Postings_0.pos, _0_Memory_1.ram, _0_Lucene41_0.doc, _0.nvd, _0_TestBloomFilteredLucene41Postings_0.doc, _0.fdx, _0.si, _0_Lucene41_0.tim, segments_6, _0.fdt, _0_Lucene41_0.tip]
[junit4:junit4]   2> 24726 T1869 C70 P20515 oasc.SolrDeletionPolicy.updateCommits newest commit = 6[_0.fnm, _0_TestBloomFilteredLucene41Postings_0.blm, _0_TestBloomFilteredLucene41Postings_0.tim, _0_Memory_0.ram, _0_Lucene41_0.pos, _0_TestBloomFilteredLucene41Postings_0.tip, _0.nvm, _0_TestBloomFilteredLucene41Postings_0.pos, _0_Memory_1.ram, _0_Lucene41_0.doc, _0.nvd, _0_TestBloomFilteredLucene41Postings_0.doc, _0.fdx, _0.si, _0_Lucene41_0.tim, segments_6, _0.fdt, _0_Lucene41_0.tip]
[junit4:junit4]   2> 24727 T1869 C70 P20515 oass.SolrIndexSearcher.<init> Opening Searcher@3349253b main
[junit4:junit4]   2> 24728 T1869 C70 P20515 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 24729 T1878 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3349253b main{StandardDirectoryReader(segments_6:3:nrt _0(4.2.1):C4)}
[junit4:junit4]   2> 24730 T1869 C70 P20515 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:53253/collection1/, StdNode: http://127.0.0.1:54989/collection1/, StdNode: http://127.0.0.1:17812/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4]   2> 24732 T1897 C69 P54989 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 24732 T1881 C68 P53253 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 24733 T1913 C71 P17812 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 24738 T1897 C69 P54989 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c2ade30 lockFactory=org.apache.lucene.store.NativeFSLockFactory@173728a7),segFN=segments_4,generation=4,filenames=[segments_4]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c2ade30 lockFactory=org.apache.lucene.store.NativeFSLockFactory@173728a7),segFN=segments_5,generation=5,filenames=[_0.fnm, _0_TestBloomFilteredLucene41Postings_0.blm, _0_TestBloomFilteredLucene41Postings_0.tim, _0_Memory_0.ram, _0_Lucene41_0.pos, _0_TestBloomFilteredLucene41Postings_0.tip, _0.nvm, _0_TestBloomFilteredLucene41Postings_0.pos, _0_Memory_1.ram, _0_Lucene41_0.doc, _0.nvd, _0_TestBloomFilteredLucene41Postings_0.doc, _0.fdx, _0.si, segments_5, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip]
[junit4:junit4]   2> 24738 T1881 C68 P53253 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@19c5437a lockFactory=org.apache.lucene.store.NativeFSLockFactory@713b17d8),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@19c5437a lockFactory=org.apache.lucene.store.NativeFSLockFactory@713b17d8),segFN=segments_4,generation=4,filenames=[_0.fnm, _0_TestBloomFilteredLucene41Postings_0.blm, _0_TestBloomFilteredLucene41Postings_0.tim, _0_Memory_0.ram, _0_Lucene41_0.pos, _0_TestBloomFilteredLucene41Postings_0.tip, _0.nvm, _0_TestBloomFilteredLucene41Postings_0.pos, _0_Memory_1.ram, _0_Lucene41_0.doc, _0.nvd, _0_TestBloomFilteredLucene41Postings_0.doc, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, segments_4]
[junit4:junit4]   2> 24738 T1897 C69 P54989 oasc.SolrDeletionPolicy.updateCommits newest commit = 5[_0.fnm, _0_TestBloomFilteredLucene41Postings_0.blm, _0_TestBloomFilteredLucene41Postings_0.tim, _0_Memory_0.ram, _0_Lucene41_0.pos, _0_TestBloomFilteredLucene41Postings_0.tip, _0.nvm, _0_TestBloomFilteredLucene41Postings_0.pos, _0_Memory_1.ram, _0_Lucene41_0.doc, _0.nvd, _0_TestBloomFilteredLucene41Postings_0.doc, _0.fdx, _0.si, segments_5, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip]
[junit4:junit4]   2> 24739 T1881 C68 P53253 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[_0.fnm, _0_TestBloomFilteredLucene41Postings_0.blm, _0_TestBloomFilteredLucene41Postings_0.tim, _0_Memory_0.ram, _0_Lucene41_0.pos, _0_TestBloomFilteredLucene41Postings_0.tip, _0.nvm, _0_TestBloomFilteredLucene41Postings_0.pos, _0_Memory_1.ram, _0_Lucene41_0.doc, _0.nvd, _0_TestBloomFilteredLucene41Postings_0.doc, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, segments_4]
[junit4:junit4]   2> 24739 T1913 C71 P17812 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@140ecfa6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@32e36fb5),segFN=segments_5,generation=5,filenames=[segments_5]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@140ecfa6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@32e36fb5),segFN=segments_6,generation=6,filenames=[_0.fnm, _0_TestBloomFilteredLucene41Postings_0.blm, _0_TestBloomFilteredLucene41Postings_0.tim, _0_Memory_0.ram, _0_Lucene41_0.pos, _0_TestBloomFilteredLucene41Postings_0.tip, _0.nvm, _0_TestBloomFilteredLucene41Postings_0.pos, _0_Memory_1.ram, _0_Lucene41_0.doc, _0.nvd, _0_TestBloomFilteredLucene41Postings_0.doc, _0.fdx, _0.si, _0_Lucene41_0.tim, segments_6, _0.fdt, _0_Lucene41_0.tip]
[junit4:junit4]   2> 24739 T1913 C71 P17812 oasc.SolrDeletionPolicy.updateCommits newest commit = 6[_0.fnm, _0_TestBloomFilteredLucene41Postings_0.blm, _0_TestBloomFilteredLucene41Postings_0.tim, _0_Memory_0.ram, _0_Lucene41_0.pos, _0_TestBloomFilteredLucene41Postings_0.tip, _0.nvm, _0_TestBloomFilteredLucene41Postings_0.pos, _0_Memory_1.ram, _0_Lucene41_0.doc, _0.nvd, _0_TestBloomFilteredLucene41Postings_0.doc, _0.fdx, _0.si, _0_Lucene41_0.tim, segments_6, _0.fdt, _0_Lucene41_0.tip]
[junit4:junit4]   2> 24740 T1897 C69 P54989 oass.SolrIndexSearcher.<init> Opening Searcher@271dbed9 main
[junit4:junit4]   2> 24740 T1881 C68 P53253 oass.SolrIndexSearcher.<init> Opening Searcher@457dbdb main
[junit4:junit4]   2> 24741 T1897 C69 P54989 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 24741 T1913 C71 P17812 oass.SolrIndexSearcher.<init> Opening Searcher@7f08d83c main
[junit4:junit4]   2> 24741 T1881 C68 P53253 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 24741 T1909 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@271dbed9 main{StandardDirectoryReader(segments_5:3:nrt _0(4.2.1):C3)}
[junit4:junit4]   2> 24741 T1913 C71 P17812 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 24742 T1893 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@457dbdb main{StandardDirectoryReader(segments_4:3:nrt _0(4.2.1):C2)}
[junit4:junit4]   2> 24758 T1897 C69 P54989 /update {waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 26
[junit4:junit4]   2> 24759 T1881 C68 P53253 /update {waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 27
[junit4:junit4]   2> 24759 T1927 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7f08d83c main{StandardDirectoryReader(segments_6:3:nrt _0(4.2.1):C4)}
[junit4:junit4]   2> 24760 T1913 C71 P17812 /update {waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 28
[junit4:junit4]   2> 24761 T1869 C70 P20515 /update {waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 43
[junit4:junit4]   2> 24761 T1835 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):230
[junit4:junit4]   2> 24762 T1835 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 24763 T1835 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4]   2> 24767 T1867 C70 P20515 REQ /select {tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=4 status=0 QTime=0 
[junit4:junit4]   2> 24772 T1882 C68 P53253 REQ /select {tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=2 status=0 QTime=1 
[junit4:junit4]   2> 24775 T1898 C69 P54989 REQ /select {tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=3 status=0 QTime=0 
[junit4:junit4]   2> 24779 T1914 C71 P17812 REQ /select {tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=4 status=0 QTime=1 
[junit4:junit4]   2> 24785 T1835 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 24802 T1899 oasha.CollectionsHandler.handleSyncShardAction Syncing shard : shard=shard1&action=SYNCSHARD&collection=collection1&wt=javabin&version=2
[junit4:junit4]   2> 24802 T1899 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 24814 T1871 oasha.CoreAdminHandler.handleRequestSyncAction I have been requested to sync up my shard
[junit4:junit4]   2> 24815 T1871 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:20515/collection1/
[junit4:junit4]   2> 24815 T1871 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:20515 START replicas=[http://127.0.0.1:53253/collection1/, http://127.0.0.1:54989/collection1/, http://127.0.0.1:17812/collection1/] nUpdates=100
[junit4:junit4]   2> 24818 T1900 C69 P54989 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1 
[junit4:junit4]   2> 24818 T1915 C71 P17812 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0 
[junit4:junit4]   2> 24818 T1883 C68 P53253 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1 
[junit4:junit4]   2> 24819 T1871 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:20515  Received 5 versions from 127.0.0.1:17812/collection1/
[junit4:junit4]   2> 24819 T1871 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:20515  Our versions are newer. ourLowThreshold=1430238424739086336 otherHigh=1430238424782077952
[junit4:junit4]   2> 24819 T1871 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:20515  Received 3 versions from 127.0.0.1:53253/collection1/
[junit4:junit4]   2> 24820 T1871 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:20515  Our versions are newer. ourLowThreshold=1430238424739086336 otherHigh=1

[...truncated too long message...]

ule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 140177 T1835 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> 140626 T1838 oazs.SessionTrackerImpl.run SessionTrackerImpl exited loop!
[junit4:junit4]   2> 167902 T1907 oasu.PeerSync.handleResponse WARNING PeerSync: core=collection1 url=http://127.0.0.1:54989  couldn't connect to http://127.0.0.1:53253/collection1/, counting as success
[junit4:junit4]   2> 167902 T1907 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:54989 DONE. sync succeeded
[junit4:junit4]   2> 167903 T1907 oasc.SyncStrategy.syncReplicas We have been closed, won't attempt to sync replicas back to leader
[junit4:junit4]   2> 167905 T1907 oasc.ShardLeaderElectionContext.rejoinLeaderElection Not rejoining election because CoreContainer is shutdown
[junit4:junit4]   2> 167905 T1907 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@4228abeb
[junit4:junit4]   2> 167907 T1907 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=10,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=305,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4]   2> 167907 T1907 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 167907 T1907 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 167908 T1907 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 167908 T1907 C69 P54989 oasu.TransactionLog.forceClose SEVERE Error: Forcing close of tlog{file=./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty3/tlog/tlog.0000000000000000005 refcount=1}
[junit4:junit4]   2> 167912 T1907 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 167912 T1907 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty3/index.20130322174725562
[junit4:junit4]   2> 167913 T1907 oasc.CachingDirectoryFactory.closeDirectory Removing directory: ./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty3/index.20130322174725562
[junit4:junit4]   2> 167913 T1907 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty3/index.20130322174725562
[junit4:junit4]   2> 167913 T1907 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty3/index
[junit4:junit4]   2> 167914 T1907 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty3/index
[junit4:junit4]   2> 167914 T1907 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty3
[junit4:junit4]   2> 167914 T1907 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.SyncSliceTest-1363981627381/jetty3
[junit4:junit4]   2> 167914 T1907 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 167915 T1907 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 167915 T1907 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 167915 T1907 oasc.LeaderElector$1.process WARNING  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4:junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4:junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4:junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:236)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:233)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:233)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4]   2> 
[junit4:junit4]   2> 167916 T1907 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> NOTE: test params are: codec=Lucene42: {range_facet_l=PostingsFormat(name=Memory doPackFST= true), text=PostingsFormat(name=TestBloomFilteredLucene41Postings), _version_=Lucene41(blocksize=128), rnd_b=PostingsFormat(name=Memory doPackFST= false), intDefault=Lucene41(blocksize=128), timestamp=PostingsFormat(name=Memory doPackFST= true), id=PostingsFormat(name=Memory doPackFST= false), a_t=PostingsFormat(name=Memory doPackFST= true), range_facet_sl=PostingsFormat(name=Memory doPackFST= false), range_facet_si=PostingsFormat(name=Memory doPackFST= true), other_tl1=Lucene41(blocksize=128), multiDefault=PostingsFormat(name=Memory doPackFST= true), a_si=Lucene41(blocksize=128)}, docValues:{}, sim=DefaultSimilarity, locale=hr_HR, timezone=Brazil/DeNoronha
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Oracle Corporation 1.7.0_17 (64-bit)/cpus=16,threads=3,free=195146440,total=346030080
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestAtomicUpdateErrorCases, TestSort, TestStressLucene, FileBasedSpellCheckerTest, SoftAutoCommitTest, TestBinaryResponseWriter, ShowFileRequestHandlerTest, TestDFRSimilarityFactory, DistributedQueryElevationComponentTest, TestBinaryField, TestFoldingMultitermQuery, TestFastWriter, TestExtendedDismaxParser, SOLR749Test, TestNumberUtils, DirectSolrConnectionTest, TestSolrJ, ZkNodePropsTest, NoCacheHeaderTest, TestGroupingSearch, RecoveryZkTest, ClusterStateTest, TestCollationKeyRangeQueries, OverseerTest, PathHierarchyTokenizerFactoryTest, StandardRequestHandlerTest, RequiredFieldsTest, SuggesterFSTTest, LeaderElectionTest, CSVRequestHandlerTest, TestRangeQuery, TestCSVLoader, JsonLoaderTest, ChaosMonkeyNothingIsSafeTest, SolrCmdDistributorTest, ResourceLoaderTest, TestSurroundQueryParser, SolrIndexConfigTest, SimpleFacetsTest, TestReversedWildcardFilterFactory, EchoParamsTest, TestSolrQueryParser, ClusterStateUpdateTest, PolyFieldTest, TestIndexingPerformance, SignatureUpdateProcessorFactoryTest, TestRealTimeGet, TestSolrDeletionPolicy1, CurrencyFieldXmlFileTest, LegacyHTMLStripCharFilterTest, IndexBasedSpellCheckerTest, ResponseLogComponentTest, SliceStateTest, TestConfig, TestFastLRUCache, TestSweetSpotSimilarityFactory, ChaosMonkeySafeLeaderTest, TestLMDirichletSimilarityFactory, FieldAnalysisRequestHandlerTest, TestDynamicFieldResource, TestTrie, TestLazyCores, TermsComponentTest, SpellPossibilityIteratorTest, SyncSliceTest]
[junit4:junit4] Completed on J0 in 168.24s, 1 test, 1 failure <<< FAILURES!

[...truncated 469 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/build.xml:381: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/build.xml:361: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/build.xml:183: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/lucene/common-build.xml:1213: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.2.1-java7/lucene/common-build.xml:877: There were test failures: 269 suites, 1134 tests, 1 failure, 23 ignored (4 assumptions)

Total time: 45 minutes 48 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message