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.x-Java6 - Build # 1355 - Still Failing
Date Wed, 20 Feb 2013 08:05:23 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/1355/

1 tests failed.
FAILED:  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:53200/xioj/l/collection1skip list:[org.apache.solr.cloud.AbstractFullDistribZkTestBase$CloudJettyRunner@75b18fc, org.apache.solr.cloud.AbstractFullDistribZkTestBase$CloudJettyRunner@4220871]

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:53200/xioj/l/collection1skip list:[org.apache.solr.cloud.AbstractFullDistribZkTestBase$CloudJettyRunner@75b18fc, org.apache.solr.cloud.AbstractFullDistribZkTestBase$CloudJettyRunner@4220871]
	at __randomizedtesting.SeedInfo.seed([B647BCC36CF745DA:37A132DB1BA825E6]: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:216)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:794)
	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:616)
	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:679)




Build Log:
[...truncated 8768 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.SyncSliceTest
[junit4:junit4]   2> 0 T3416 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /xioj/l
[junit4:junit4]   2> 4 T3416 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-SyncSliceTest-1361347349315
[junit4:junit4]   2> 5 T3416 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 6 T3417 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 9 T3417 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 9 T3417 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4]   2> 9 T3417 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4]   2> 10 T3417 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 11 T3417 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4]   2> 107 T3416 oasc.ZkTestServer.run start zk server on port:53187
[junit4:junit4]   2> 107 T3416 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:53187 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@10c7f3ab
[junit4:junit4]   2> 108 T3416 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 109 T3422 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:53187. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 109 T3422 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:53187, initiating session
[junit4:junit4]   2> 109 T3418 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:53188
[junit4:junit4]   2> 110 T3418 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:53188
[junit4:junit4]   2> 110 T3420 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 113 T3420 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf6a00b4a0000 with negotiated timeout 10000 for client /140.211.11.196:53188
[junit4:junit4]   2> 113 T3422 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:53187, sessionid = 0x13cf6a00b4a0000, negotiated timeout = 10000
[junit4:junit4]   2> 113 T3423 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10c7f3ab name:ZooKeeperConnection Watcher:127.0.0.1:53187 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 114 T3416 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 114 T3416 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 128 T3421 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf6a00b4a0000
[junit4:junit4]   2> 129 T3423 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 130 T3418 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:53188 which had sessionid 0x13cf6a00b4a0000
[junit4:junit4]   2> 129 T3416 oaz.ZooKeeper.close Session: 0x13cf6a00b4a0000 closed
[junit4:junit4]   2> 130 T3416 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:53187/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@b4ff64d
[junit4:junit4]   2> 131 T3416 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 131 T3424 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:53187. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 132 T3424 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:53187, initiating session
[junit4:junit4]   2> 132 T3418 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:53189
[junit4:junit4]   2> 132 T3418 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:53189
[junit4:junit4]   2> 134 T3420 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf6a00b4a0001 with negotiated timeout 10000 for client /140.211.11.196:53189
[junit4:junit4]   2> 134 T3424 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:53187, sessionid = 0x13cf6a00b4a0001, negotiated timeout = 10000
[junit4:junit4]   2> 134 T3425 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b4ff64d name:ZooKeeperConnection Watcher:127.0.0.1:53187/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 134 T3416 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 135 T3416 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 144 T3416 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 146 T3416 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 148 T3416 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 158 T3416 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 165 T3416 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 177 T3416 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 178 T3416 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 281 T3416 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 282 T3416 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 284 T3416 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 285 T3416 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 295 T3416 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 296 T3416 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 299 T3416 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 299 T3416 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 303 T3416 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 303 T3416 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 306 T3416 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 307 T3416 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 309 T3416 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 310 T3416 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 318 T3421 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf6a00b4a0001
[junit4:junit4]   2> 319 T3425 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 319 T3418 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:53189 which had sessionid 0x13cf6a00b4a0001
[junit4:junit4]   2> 319 T3416 oaz.ZooKeeper.close Session: 0x13cf6a00b4a0001 closed
[junit4:junit4]   2> 482 T3416 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 486 T3416 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:53190
[junit4:junit4]   2> 487 T3416 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 488 T3416 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 488 T3416 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-1361347349629
[junit4:junit4]   2> 489 T3416 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-1361347349629/solr.xml
[junit4:junit4]   2> 489 T3416 oasc.CoreContainer.<init> New CoreContainer 1953831624
[junit4:junit4]   2> 490 T3416 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-1361347349629/'
[junit4:junit4]   2> 490 T3416 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-1361347349629/'
[junit4:junit4]   2> 536 T3416 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 537 T3416 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 537 T3416 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 538 T3416 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 538 T3416 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 539 T3416 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 539 T3416 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 540 T3416 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 540 T3416 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 541 T3416 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 561 T3416 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 579 T3416 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:53187/solr
[junit4:junit4]   2> 579 T3416 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 580 T3416 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:53187 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1cd1130a
[junit4:junit4]   2> 581 T3416 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 581 T3435 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:53187. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 582 T3435 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:53187, initiating session
[junit4:junit4]   2> 582 T3418 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:53191
[junit4:junit4]   2> 583 T3418 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:53191
[junit4:junit4]   2> 585 T3420 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf6a00b4a0002 with negotiated timeout 20000 for client /140.211.11.196:53191
[junit4:junit4]   2> 585 T3435 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:53187, sessionid = 0x13cf6a00b4a0002, negotiated timeout = 20000
[junit4:junit4]   2> 585 T3436 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cd1130a name:ZooKeeperConnection Watcher:127.0.0.1:53187 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 585 T3416 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 586 T3421 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf6a00b4a0002
[junit4:junit4]   2> 597 T3436 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 598 T3418 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:53191 which had sessionid 0x13cf6a00b4a0002
[junit4:junit4]   2> 597 T3416 oaz.ZooKeeper.close Session: 0x13cf6a00b4a0002 closed
[junit4:junit4]   2> 598 T3416 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 609 T3416 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:53187/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@6f4809f6
[junit4:junit4]   2> 610 T3416 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 610 T3437 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:53187. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 610 T3437 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:53187, initiating session
[junit4:junit4]   2> 611 T3418 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:53192
[junit4:junit4]   2> 611 T3418 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:53192
[junit4:junit4]   2> 612 T3420 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf6a00b4a0003 with negotiated timeout 20000 for client /140.211.11.196:53192
[junit4:junit4]   2> 612 T3437 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:53187, sessionid = 0x13cf6a00b4a0003, negotiated timeout = 20000
[junit4:junit4]   2> 613 T3438 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6f4809f6 name:ZooKeeperConnection Watcher:127.0.0.1:53187/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 613 T3416 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 615 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 624 T3416 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 627 T3416 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53190_xioj%2Fl
[junit4:junit4]   2> 628 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:53190_xioj%2Fl Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:53190_xioj%2Fl
[junit4:junit4]   2> 629 T3416 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53190_xioj%2Fl
[junit4:junit4]   2> 638 T3416 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 652 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0003 type:delete cxid:0x16 zxid:0x21 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 653 T3416 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 656 T3416 oasc.Overseer.start Overseer (id=89217259885166595-127.0.0.1:53190_xioj%2Fl-n_0000000000) starting
[junit4:junit4]   2> 657 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 664 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 665 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 672 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 673 T3440 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 674 T3416 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 682 T3416 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 684 T3439 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 688 T3441 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-1361347349629/collection1
[junit4:junit4]   2> 689 T3441 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 689 T3441 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 689 T3441 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 690 T3441 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-1361347349629/collection1/'
[junit4:junit4]   2> 692 T3441 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-controljetty-1361347349629/collection1/lib/README' to classloader
[junit4:junit4]   2> 692 T3441 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-controljetty-1361347349629/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 738 T3441 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 794 T3441 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 895 T3441 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 900 T3441 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1491 T3441 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1501 T3441 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1505 T3441 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1515 T3441 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1520 T3441 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1523 T3441 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1524 T3441 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1525 T3441 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-1361347349629/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1361347349315/control/data/
[junit4:junit4]   2> 1526 T3441 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d762027
[junit4:junit4]   2> 1526 T3441 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 1527 T3441 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/control/data forceNew:false
[junit4:junit4]   2> 1528 T3441 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/control/data
[junit4:junit4]   2> 1528 T3441 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1361347349315/control/data/index/
[junit4:junit4]   2> 1529 T3441 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1361347349315/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1530 T3441 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/control/data/index forceNew:false
[junit4:junit4]   2> 1536 T3441 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d4a00ff; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1536 T3441 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 1537 T3441 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/control/data/index
[junit4:junit4]   2> 1539 T3441 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1539 T3441 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1539 T3441 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1540 T3441 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1540 T3441 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1541 T3441 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1541 T3441 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1541 T3441 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1542 T3441 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1548 T3441 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1554 T3441 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/control/data
[junit4:junit4]   2> 1555 T3441 oass.SolrIndexSearcher.<init> Opening Searcher@1df71df7 main
[junit4:junit4]   2> 1556 T3441 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1556 T3441 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1559 T3441 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/control/data
[junit4:junit4]   2> 1560 T3442 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1df71df7 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1560 T3441 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 1561 T3441 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1561 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0003 type:create cxid:0x50 zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4]   2> 2187 T3439 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2188 T3439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53190_xioj%2Fl",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53190/xioj/l"}
[junit4:junit4]   2> 2188 T3439 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 2188 T3439 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 2189 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0003 type:create cxid:0x58 zxid:0x2c txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 2205 T3438 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> 2574 T3441 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 2574 T3441 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53190/xioj/l collection:control_collection shard:shard1
[junit4:junit4]   2> 2575 T3441 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 2619 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0003 type:delete cxid:0x72 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 2636 T3441 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 2636 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0003 type:create cxid:0x73 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2676 T3441 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2676 T3441 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2677 T3441 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53190/xioj/l/collection1/
[junit4:junit4]   2> 2677 T3441 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 2677 T3441 oasc.SyncStrategy.syncToMe http://127.0.0.1:53190/xioj/l/collection1/ has no replicas
[junit4:junit4]   2> 2677 T3441 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53190/xioj/l/collection1/
[junit4:junit4]   2> 2678 T3441 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 2704 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0003 type:create cxid:0x7d zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3709 T3439 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3734 T3438 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> 3755 T3441 oasc.ZkController.register We are http://127.0.0.1:53190/xioj/l/collection1/ and leader is http://127.0.0.1:53190/xioj/l/collection1/
[junit4:junit4]   2> 3755 T3441 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53190/xioj/l
[junit4:junit4]   2> 3755 T3441 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 3755 T3441 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 3756 T3441 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 3757 T3441 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3758 T3416 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 3759 T3416 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 3759 T3416 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 3774 T3416 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 3775 T3416 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:53187/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@478810a6
[junit4:junit4]   2> 3776 T3416 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3777 T3443 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:53187. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 3777 T3443 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:53187, initiating session
[junit4:junit4]   2> 3777 T3418 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:53193
[junit4:junit4]   2> 3778 T3418 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:53193
[junit4:junit4]   2> 3779 T3420 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf6a00b4a0004 with negotiated timeout 10000 for client /140.211.11.196:53193
[junit4:junit4]   2> 3779 T3443 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:53187, sessionid = 0x13cf6a00b4a0004, negotiated timeout = 10000
[junit4:junit4]   2> 3779 T3444 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@478810a6 name:ZooKeeperConnection Watcher:127.0.0.1:53187/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3779 T3416 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3780 T3416 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3782 T3416 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 3947 T3416 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 3950 T3416 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:53194
[junit4:junit4]   2> 3951 T3416 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 3951 T3416 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3952 T3416 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1361347353092
[junit4:junit4]   2> 3952 T3416 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1361347353092/solr.xml
[junit4:junit4]   2> 3953 T3416 oasc.CoreContainer.<init> New CoreContainer 762788429
[junit4:junit4]   2> 3953 T3416 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1361347353092/'
[junit4:junit4]   2> 3954 T3416 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1361347353092/'
[junit4:junit4]   2> 4000 T3416 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 4001 T3416 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 4001 T3416 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 4001 T3416 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 4002 T3416 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 4002 T3416 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 4003 T3416 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 4003 T3416 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 4004 T3416 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 4004 T3416 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 4024 T3416 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 4042 T3416 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:53187/solr
[junit4:junit4]   2> 4043 T3416 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 4044 T3416 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:53187 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@62cc540b
[junit4:junit4]   2> 4045 T3416 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4045 T3454 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:53187. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 4046 T3454 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:53187, initiating session
[junit4:junit4]   2> 4046 T3418 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:53195
[junit4:junit4]   2> 4046 T3418 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:53195
[junit4:junit4]   2> 4048 T3420 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf6a00b4a0005 with negotiated timeout 20000 for client /140.211.11.196:53195
[junit4:junit4]   2> 4048 T3454 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:53187, sessionid = 0x13cf6a00b4a0005, negotiated timeout = 20000
[junit4:junit4]   2> 4049 T3455 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@62cc540b name:ZooKeeperConnection Watcher:127.0.0.1:53187 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4049 T3416 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4050 T3421 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf6a00b4a0005
[junit4:junit4]   2> 4061 T3455 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 4062 T3418 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:53195 which had sessionid 0x13cf6a00b4a0005
[junit4:junit4]   2> 4061 T3416 oaz.ZooKeeper.close Session: 0x13cf6a00b4a0005 closed
[junit4:junit4]   2> 4062 T3416 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 4073 T3416 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:53187/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1a7600bb
[junit4:junit4]   2> 4074 T3416 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4074 T3456 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:53187. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 4075 T3456 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:53187, initiating session
[junit4:junit4]   2> 4075 T3418 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:53196
[junit4:junit4]   2> 4075 T3418 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:53196
[junit4:junit4]   2> 4076 T3420 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf6a00b4a0006 with negotiated timeout 20000 for client /140.211.11.196:53196
[junit4:junit4]   2> 4076 T3456 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:53187, sessionid = 0x13cf6a00b4a0006, negotiated timeout = 20000
[junit4:junit4]   2> 4077 T3457 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a7600bb name:ZooKeeperConnection Watcher:127.0.0.1:53187/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4077 T3416 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4078 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0006 type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4079 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0006 type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4088 T3416 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 5090 T3416 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53194_xioj%2Fl
[junit4:junit4]   2> 5091 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0006 type:delete cxid:0x9 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:53194_xioj%2Fl Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:53194_xioj%2Fl
[junit4:junit4]   2> 5092 T3416 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53194_xioj%2Fl
[junit4:junit4]   2> 5094 T3438 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 5095 T3444 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5095 T3457 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5106 T3438 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5112 T3458 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1361347353092/collection1
[junit4:junit4]   2> 5112 T3458 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 5113 T3458 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 5113 T3458 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 5114 T3458 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1361347353092/collection1/'
[junit4:junit4]   2> 5115 T3458 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty1-1361347353092/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 5116 T3458 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty1-1361347353092/collection1/lib/README' to classloader
[junit4:junit4]   2> 5161 T3458 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 5215 T3458 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 5245 T3439 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5246 T3439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53190_xioj%2Fl",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53190/xioj/l"}
[junit4:junit4]   2> 5260 T3444 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> 5260 T3438 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> 5316 T3458 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 5316 T3457 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> 5322 T3458 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 5914 T3458 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 5925 T3458 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 5929 T3458 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 5940 T3458 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5944 T3458 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5948 T3458 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5949 T3458 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5950 T3458 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1361347353092/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/
[junit4:junit4]   2> 5951 T3458 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d762027
[junit4:junit4]   2> 5951 T3458 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 5952 T3458 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1 forceNew:false
[junit4:junit4]   2> 5953 T3458 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1
[junit4:junit4]   2> 5953 T3458 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index/
[junit4:junit4]   2> 5954 T3458 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 5955 T3458 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index forceNew:false
[junit4:junit4]   2> 5961 T3458 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@bebc341; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 5961 T3458 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 5962 T3458 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index
[junit4:junit4]   2> 5964 T3458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 5964 T3458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 5965 T3458 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 5966 T3458 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 5966 T3458 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 5966 T3458 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 5967 T3458 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 5967 T3458 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 5968 T3458 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 5975 T3458 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 5981 T3458 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1
[junit4:junit4]   2> 5982 T3458 oass.SolrIndexSearcher.<init> Opening Searcher@1cbf348c main
[junit4:junit4]   2> 5983 T3458 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 5983 T3458 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 5988 T3459 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1cbf348c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 5989 T3458 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 5990 T3458 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 6764 T3439 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6765 T3439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53194_xioj%2Fl",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53194/xioj/l"}
[junit4:junit4]   2> 6765 T3439 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4:junit4]   2> 6765 T3439 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 6776 T3444 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> 6776 T3457 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> 6776 T3438 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> 6992 T3458 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 6992 T3458 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53194/xioj/l collection:collection1 shard:shard1
[junit4:junit4]   2> 6993 T3458 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 7019 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0006 type:delete cxid:0x46 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 7026 T3458 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 7027 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0006 type:create cxid:0x47 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7037 T3458 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 7038 T3458 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 7038 T3458 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53194/xioj/l/collection1/
[junit4:junit4]   2> 7038 T3458 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 7038 T3458 oasc.SyncStrategy.syncToMe http://127.0.0.1:53194/xioj/l/collection1/ has no replicas
[junit4:junit4]   2> 7039 T3458 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53194/xioj/l/collection1/
[junit4:junit4]   2> 7039 T3458 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 7053 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0006 type:create cxid:0x51 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8280 T3439 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8323 T3457 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> 8323 T3438 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> 8323 T3444 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> 8339 T3458 oasc.ZkController.register We are http://127.0.0.1:53194/xioj/l/collection1/ and leader is http://127.0.0.1:53194/xioj/l/collection1/
[junit4:junit4]   2> 8339 T3458 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53194/xioj/l
[junit4:junit4]   2> 8339 T3458 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 8339 T3458 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 8340 T3458 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 8341 T3458 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8342 T3416 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 8343 T3416 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 8343 T3416 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 8554 T3416 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 8558 T3416 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:53200
[junit4:junit4]   2> 8558 T3416 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 8559 T3416 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8559 T3416 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1361347357670
[junit4:junit4]   2> 8560 T3416 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1361347357670/solr.xml
[junit4:junit4]   2> 8560 T3416 oasc.CoreContainer.<init> New CoreContainer 493513494
[junit4:junit4]   2> 8561 T3416 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1361347357670/'
[junit4:junit4]   2> 8561 T3416 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1361347357670/'
[junit4:junit4]   2> 8617 T3416 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 8617 T3416 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 8618 T3416 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 8618 T3416 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 8619 T3416 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 8619 T3416 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 8619 T3416 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 8620 T3416 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 8620 T3416 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 8621 T3416 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 8645 T3416 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 8666 T3416 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:53187/solr
[junit4:junit4]   2> 8666 T3416 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 8667 T3416 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:53187 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@35b4548f
[junit4:junit4]   2> 8668 T3416 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8668 T3469 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:53187. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 8669 T3469 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:53187, initiating session
[junit4:junit4]   2> 8669 T3418 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:53201
[junit4:junit4]   2> 8670 T3418 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:53201
[junit4:junit4]   2> 8672 T3420 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf6a00b4a0007 with negotiated timeout 20000 for client /140.211.11.196:53201
[junit4:junit4]   2> 8672 T3469 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:53187, sessionid = 0x13cf6a00b4a0007, negotiated timeout = 20000
[junit4:junit4]   2> 8673 T3470 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@35b4548f name:ZooKeeperConnection Watcher:127.0.0.1:53187 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8673 T3416 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8674 T3421 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf6a00b4a0007
[junit4:junit4]   2> 8675 T3470 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 8675 T3418 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:53201 which had sessionid 0x13cf6a00b4a0007
[junit4:junit4]   2> 8675 T3416 oaz.ZooKeeper.close Session: 0x13cf6a00b4a0007 closed
[junit4:junit4]   2> 8682 T3416 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 8693 T3416 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:53187/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@64d7a649
[junit4:junit4]   2> 8694 T3416 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8694 T3471 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:53187. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 8695 T3471 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:53187, initiating session
[junit4:junit4]   2> 8695 T3418 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:53202
[junit4:junit4]   2> 8695 T3418 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:53202
[junit4:junit4]   2> 8696 T3420 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf6a00b4a0008 with negotiated timeout 20000 for client /140.211.11.196:53202
[junit4:junit4]   2> 8697 T3471 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:53187, sessionid = 0x13cf6a00b4a0008, negotiated timeout = 20000
[junit4:junit4]   2> 8697 T3472 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@64d7a649 name:ZooKeeperConnection Watcher:127.0.0.1:53187/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8697 T3416 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8698 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0008 type:create cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8699 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0008 type:create cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8708 T3416 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9710 T3416 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53200_xioj%2Fl
[junit4:junit4]   2> 9711 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a0008 type:delete cxid:0x9 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:53200_xioj%2Fl Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:53200_xioj%2Fl
[junit4:junit4]   2> 10580 T3416 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53200_xioj%2Fl
[junit4:junit4]   2> 10581 T3439 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10581 T3439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53194_xioj%2Fl",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53194/xioj/l"}
[junit4:junit4]   2> 10583 T3444 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> 10583 T3438 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> 10596 T3472 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 10596 T3457 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 10596 T3457 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> 10603 T3444 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 10611 T3444 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> 10611 T3472 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> 10611 T3457 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> 10615 T3438 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 10615 T3438 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> 10618 T3473 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1361347357670/collection1
[junit4:junit4]   2> 10618 T3473 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 10618 T3473 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 10619 T3473 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 10620 T3473 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1361347357670/collection1/'
[junit4:junit4]   2> 10620 T3473 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty2-1361347357670/collection1/lib/README' to classloader
[junit4:junit4]   2> 10621 T3473 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty2-1361347357670/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 10654 T3473 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 10693 T3473 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 10794 T3473 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 10798 T3473 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 11205 T3473 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 11212 T3473 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 11215 T3473 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 11224 T3473 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 11228 T3473 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 11231 T3473 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 11231 T3473 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 11232 T3473 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1361347357670/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/
[junit4:junit4]   2> 11233 T3473 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d762027
[junit4:junit4]   2> 11233 T3473 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 11234 T3473 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2 forceNew:false
[junit4:junit4]   2> 11234 T3473 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2
[junit4:junit4]   2> 11234 T3473 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/index/
[junit4:junit4]   2> 11235 T3473 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 11235 T3473 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/index forceNew:false
[junit4:junit4]   2> 11265 T3473 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7cf2a936; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 11265 T3473 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 11265 T3473 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/index
[junit4:junit4]   2> 11267 T3473 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 11267 T3473 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 11267 T3473 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 11268 T3473 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 11268 T3473 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 11268 T3473 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 11269 T3473 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 11269 T3473 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 11269 T3473 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 11274 T3473 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 11278 T3473 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2
[junit4:junit4]   2> 11279 T3473 oass.SolrIndexSearcher.<init> Opening Searcher@550371aa main
[junit4:junit4]   2> 11280 T3473 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 11280 T3473 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 11283 T3474 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@550371aa main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 11285 T3473 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 11285 T3473 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 12116 T3439 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12117 T3439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53200_xioj%2Fl",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53200/xioj/l"}
[junit4:junit4]   2> 12117 T3439 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4]   2> 12117 T3439 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 12132 T3457 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> 12132 T3472 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> 12132 T3444 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> 12132 T3438 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> 12287 T3473 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 12287 T3473 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53200/xioj/l collection:collection1 shard:shard1
[junit4:junit4]   2> 12290 T3473 oasc.ZkController.register We are http://127.0.0.1:53200/xioj/l/collection1/ and leader is http://127.0.0.1:53194/xioj/l/collection1/
[junit4:junit4]   2> 12290 T3473 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53200/xioj/l
[junit4:junit4]   2> 12290 T3473 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 12290 T3473 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C254 name=collection1 org.apache.solr.core.SolrCore@3b781fe1 url=http://127.0.0.1:53200/xioj/l/collection1 node=127.0.0.1:53200_xioj%2Fl C254_STATE=coll:collection1 core:collection1 props:{shard=null, roles=null, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:53200_xioj%2Fl, base_url=http://127.0.0.1:53200/xioj/l}
[junit4:junit4]   2> 12291 T3475 C254 P53200 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 12291 T3473 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12291 T3475 C254 P53200 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 12292 T3475 C254 P53200 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 12292 T3475 C254 P53200 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 12292 T3416 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 12292 T3416 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 12293 T3416 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 12293 T3475 C254 P53200 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 12434 T3416 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 12436 T3416 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:53205
[junit4:junit4]   2> 12437 T3416 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 12438 T3416 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 12438 T3416 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1361347361617
[junit4:junit4]   2> 12439 T3416 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1361347361617/solr.xml
[junit4:junit4]   2> 12439 T3416 oasc.CoreContainer.<init> New CoreContainer 434163547
[junit4:junit4]   2> 12440 T3416 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1361347361617/'
[junit4:junit4]   2> 12440 T3416 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1361347361617/'
[junit4:junit4]   2> 12489 T3416 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 12490 T3416 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 12491 T3416 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 12491 T3416 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 12491 T3416 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 12492 T3416 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 12492 T3416 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 12493 T3416 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 12493 T3416 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 12494 T3416 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 12514 T3416 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 12532 T3416 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:53187/solr
[junit4:junit4]   2> 12533 T3416 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 12534 T3416 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:53187 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@55173c5b
[junit4:junit4]   2> 12535 T3416 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12535 T3485 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:53187. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 12536 T3485 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:53187, initiating session
[junit4:junit4]   2> 12536 T3418 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:53206
[junit4:junit4]   2> 12537 T3418 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:53206
[junit4:junit4]   2> 12539 T3420 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf6a00b4a0009 with negotiated timeout 20000 for client /140.211.11.196:53206
[junit4:junit4]   2> 12539 T3485 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:53187, sessionid = 0x13cf6a00b4a0009, negotiated timeout = 20000
[junit4:junit4]   2> 12539 T3486 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55173c5b name:ZooKeeperConnection Watcher:127.0.0.1:53187 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12540 T3416 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12541 T3421 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf6a00b4a0009
[junit4:junit4]   2> 12584 T3486 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 12584 T3418 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:53206 which had sessionid 0x13cf6a00b4a0009
[junit4:junit4]   2> 12584 T3416 oaz.ZooKeeper.close Session: 0x13cf6a00b4a0009 closed
[junit4:junit4]   2> 12585 T3416 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 12596 T3416 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:53187/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1f57c6e6
[junit4:junit4]   2> 12597 T3416 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12597 T3487 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:53187. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 12598 T3487 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:53187, initiating session
[junit4:junit4]   2> 12598 T3418 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:53207
[junit4:junit4]   2> 12598 T3418 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:53207
[junit4:junit4]   2> 12612 T3420 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf6a00b4a000a with negotiated timeout 20000 for client /140.211.11.196:53207
[junit4:junit4]   2> 12612 T3487 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:53187, sessionid = 0x13cf6a00b4a000a, negotiated timeout = 20000
[junit4:junit4]   2> 12612 T3488 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f57c6e6 name:ZooKeeperConnection Watcher:127.0.0.1:53187/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12613 T3416 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12613 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a000a type:create cxid:0x1 zxid:0x80 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12654 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a000a type:create cxid:0x2 zxid:0x81 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12676 T3416 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 13635 T3439 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13636 T3439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53200_xioj%2Fl",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53200/xioj/l"}
[junit4:junit4]   2> 13649 T3457 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> 13649 T3444 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> 13649 T3488 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> 13649 T3472 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> 13649 T3438 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> 13679 T3416 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53205_xioj%2Fl
[junit4:junit4]   2> 13680 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a000a type:delete cxid:0xb zxid:0x86 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:53205_xioj%2Fl Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:53205_xioj%2Fl
[junit4:junit4]   2> 13681 T3416 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53205_xioj%2Fl
[junit4:junit4]   2> 13692 T3444 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> 13692 T3438 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> 13692 T3488 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13693 T3457 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13693 T3472 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13693 T3488 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> 13693 T3457 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> 13693 T3472 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> 13694 T3438 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13700 T3444 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13706 T3489 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1361347361617/collection1
[junit4:junit4]   2> 13706 T3489 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 13707 T3489 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 13707 T3489 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 13708 T3489 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1361347361617/collection1/'
[junit4:junit4]   2> 13709 T3489 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty3-1361347361617/collection1/lib/README' to classloader
[junit4:junit4]   2> 13710 T3489 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty3-1361347361617/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 13758 T3489 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 13819 T3489 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 13920 T3489 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 13926 T3489 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 14571 T3489 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 14582 T3489 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 14586 T3489 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 14597 T3489 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14602 T3489 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14606 T3489 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14613 T3489 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14614 T3489 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1361347361617/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/
[junit4:junit4]   2> 14614 T3489 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d762027
[junit4:junit4]   2> 14615 T3489 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 14616 T3489 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3 forceNew:false
[junit4:junit4]   2> 14617 T3489 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3
[junit4:junit4]   2> 14617 T3489 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/index/
[junit4:junit4]   2> 14618 T3489 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 14619 T3489 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/index forceNew:false
[junit4:junit4]   2> 14652 T3489 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@12d8c691; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 14652 T3489 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 14653 T3489 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/index
[junit4:junit4]   2> 14655 T3489 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 14656 T3489 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 14656 T3489 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 14657 T3489 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 14657 T3489 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 14658 T3489 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 14658 T3489 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 14659 T3489 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 14659 T3489 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 14666 T3489 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 14672 T3489 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3
[junit4:junit4]   2> 14674 T3489 oass.SolrIndexSearcher.<init> Opening Searcher@3bcfac98 main
[junit4:junit4]   2> 14675 T3489 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 14675 T3489 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 14679 T3490 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3bcfac98 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 14680 T3489 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 14681 T3489 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 15154 T3439 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15155 T3439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53205_xioj%2Fl",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53205/xioj/l"}
[junit4:junit4]   2> 15155 T3439 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4]   2> 15155 T3439 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 15170 T3488 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> 15170 T3472 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> 15170 T3457 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> 15170 T3444 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> 15170 T3438 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> 15683 T3489 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 15683 T3489 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53205/xioj/l collection:collection1 shard:shard1
[junit4:junit4]   2> 15686 T3489 oasc.ZkController.register We are http://127.0.0.1:53205/xioj/l/collection1/ and leader is http://127.0.0.1:53194/xioj/l/collection1/
[junit4:junit4]   2> 15686 T3489 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53205/xioj/l
[junit4:junit4]   2> 15686 T3489 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 15686 T3489 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C255 name=collection1 org.apache.solr.core.SolrCore@26bb0e64 url=http://127.0.0.1:53205/xioj/l/collection1 node=127.0.0.1:53205_xioj%2Fl C255_STATE=coll:collection1 core:collection1 props:{shard=null, roles=null, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:53205_xioj%2Fl, base_url=http://127.0.0.1:53205/xioj/l}
[junit4:junit4]   2> 15688 T3491 C255 P53205 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 15688 T3489 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15688 T3491 C255 P53205 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 15689 T3491 C255 P53205 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 15689 T3491 C255 P53205 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 15689 T3416 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 15690 T3416 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 15690 T3491 C255 P53205 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 15690 T3416 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 15873 T3416 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 15876 T3416 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:28083
[junit4:junit4]   2> 15877 T3416 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 15877 T3416 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 15878 T3416 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty4-1361347365020
[junit4:junit4]   2> 15878 T3416 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty4-1361347365020/solr.xml
[junit4:junit4]   2> 15879 T3416 oasc.CoreContainer.<init> New CoreContainer 1347016158
[junit4:junit4]   2> 15879 T3416 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty4-1361347365020/'
[junit4:junit4]   2> 15880 T3416 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty4-1361347365020/'
[junit4:junit4]   2> 15926 T3416 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 15926 T3416 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 15927 T3416 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 15927 T3416 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 15928 T3416 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 15928 T3416 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 15929 T3416 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 15929 T3416 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 15930 T3416 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 15930 T3416 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 15948 T3416 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 15966 T3416 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:53187/solr
[junit4:junit4]   2> 15967 T3416 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 15967 T3416 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:53187 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@21a3d24
[junit4:junit4]   2> 15968 T3416 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 15968 T3501 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:53187. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 15969 T3501 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:53187, initiating session
[junit4:junit4]   2> 15970 T3418 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:34762
[junit4:junit4]   2> 15970 T3418 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:34762
[junit4:junit4]   2> 15972 T3420 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf6a00b4a000b with negotiated timeout 20000 for client /140.211.11.196:34762
[junit4:junit4]   2> 15972 T3501 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:53187, sessionid = 0x13cf6a00b4a000b, negotiated timeout = 20000
[junit4:junit4]   2> 15972 T3502 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@21a3d24 name:ZooKeeperConnection Watcher:127.0.0.1:53187 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 15972 T3416 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 15973 T3421 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cf6a00b4a000b
[junit4:junit4]   2> 15974 T3502 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 15974 T3418 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:34762 which had sessionid 0x13cf6a00b4a000b
[junit4:junit4]   2> 15974 T3416 oaz.ZooKeeper.close Session: 0x13cf6a00b4a000b closed
[junit4:junit4]   2> 15975 T3416 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 15984 T3416 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:53187/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@b13c17
[junit4:junit4]   2> 15985 T3416 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 15985 T3503 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:53187. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 15986 T3503 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:53187, initiating session
[junit4:junit4]   2> 15986 T3418 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:51807
[junit4:junit4]   2> 15986 T3418 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:51807
[junit4:junit4]   2> 15988 T3420 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cf6a00b4a000c with negotiated timeout 20000 for client /140.211.11.196:51807
[junit4:junit4]   2> 15988 T3503 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:53187, sessionid = 0x13cf6a00b4a000c, negotiated timeout = 20000
[junit4:junit4]   2> 15988 T3504 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b13c17 name:ZooKeeperConnection Watcher:127.0.0.1:53187/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 15988 T3416 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 15989 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a000c type:create cxid:0x1 zxid:0x93 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 15990 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a000c type:create cxid:0x2 zxid:0x94 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 15999 T3416 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2>  C254_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:53200_xioj%2Fl, base_url=http://127.0.0.1:53200/xioj/l}
[junit4:junit4]   2> 16312 T3475 C254 P53200 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:53194/xioj/l/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 16312 T3475 C254 P53200 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:53200/xioj/l START replicas=[http://127.0.0.1:53194/xioj/l/collection1/] nUpdates=100
[junit4:junit4]   2> 16329 T3475 C254 P53200 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 16330 T3475 C254 P53200 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 16330 T3475 C254 P53200 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 16330 T3475 C254 P53200 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 16330 T3475 C254 P53200 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 16331 T3475 C254 P53200 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:53194/xioj/l/collection1/. core=collection1
[junit4:junit4]   2> 16331 T3475 C254 P53200 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C256 name=collection1 org.apache.solr.core.SolrCore@5c72a676 url=http://127.0.0.1:53194/xioj/l/collection1 node=127.0.0.1:53194_xioj%2Fl C256_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:53194_xioj%2Fl, base_url=http://127.0.0.1:53194/xioj/l, leader=true}
[junit4:junit4]   2> 16336 T3449 C256 P53194 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16340 T3450 C256 P53194 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16341 T3450 C256 P53194 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1
[junit4:junit4]   2> 16345 T3450 C256 P53194 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@bebc341; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 16345 T3450 C256 P53194 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 16350 T3450 C256 P53194 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@bebc341; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@bebc341; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 16350 T3450 C256 P53194 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 16351 T3450 C256 P53194 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1
[junit4:junit4]   2> 16352 T3450 C256 P53194 oass.SolrIndexSearcher.<init> Opening Searcher@6b0286f realtime
[junit4:junit4]   2> 16352 T3450 C256 P53194 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16352 T3450 C256 P53194 /update {waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 12
[junit4:junit4]   2> 16353 T3475 C254 P53200 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 16353 T3475 C254 P53200 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 16355 T3451 C256 P53194 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 16355 T3451 C256 P53194 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16356 T3475 C254 P53200 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 16356 T3475 C254 P53200 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 16356 T3475 C254 P53200 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 16359 T3451 C256 P53194 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1
[junit4:junit4]   2> 16360 T3451 C256 P53194 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index
[junit4:junit4]   2> 16360 T3451 C256 P53194 REQ /replication {command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16361 T3475 C254 P53200 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 16362 T3475 C254 P53200 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/index.20130220020245671 forceNew:false
[junit4:junit4]   2> 16362 T3475 C254 P53200 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2
[junit4:junit4]   2> 16363 T3475 C254 P53200 oash.SnapPuller.fetchLatestIndex Starting download to NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/index.20130220020245671 lockFactory=org.apache.lucene.store.NativeFSLockFactory@541f0140; maxCacheMB=48.0 maxMergeSizeMB=4.0) fullCopy=true
[junit4:junit4]   2> 16366 T3451 C256 P53194 REQ /replication {file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
[junit4:junit4]   2> 16367 T3475 C254 P53200 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/index
[junit4:junit4]   2> 16368 T3475 C254 P53200 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 16368 T3475 C254 P53200 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130220020245671
[junit4:junit4]   2> 16369 T3475 C254 P53200 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2
[junit4:junit4]   2> 16370 T3475 C254 P53200 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2
[junit4:junit4]   2> 16370 T3475 C254 P53200 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/index/ new=./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/index.20130220020245671
[junit4:junit4]   2> 16373 T3475 C254 P53200 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/index.20130220020245671 lockFactory=org.apache.lucene.store.NativeFSLockFactory@541f0140; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 16374 T3475 C254 P53200 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 16375 T3475 C254 P53200 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2
[junit4:junit4]   2> 16375 T3475 C254 P53200 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 16375 T3475 C254 P53200 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 16375 T3475 C254 P53200 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 16376 T3475 C254 P53200 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/index.20130220020245671
[junit4:junit4]   2> 16377 T3475 C254 P53200 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2
[junit4:junit4]   2> 16380 T3475 C254 P53200 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/index.20130220020245671 lockFactory=org.apache.lucene.store.NativeFSLockFactory@541f0140; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 16380 T3475 C254 P53200 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 16380 T3475 C254 P53200 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 16381 T3475 C254 P53200 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2
[junit4:junit4]   2> 16381 T3475 C254 P53200 oass.SolrIndexSearcher.<init> Opening Searcher@49fa3ce7 main
[junit4:junit4]   2> 16382 T3474 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@49fa3ce7 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 16383 T3474 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/index
[junit4:junit4]   2> 16383 T3475 C254 P53200 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=false,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16386 T3475 C254 P53200 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/index.20130220020245671 lockFactory=org.apache.lucene.store.NativeFSLockFactory@541f0140; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/index.20130220020245671 lockFactory=org.apache.lucene.store.NativeFSLockFactory@541f0140; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   2> 16387 T3475 C254 P53200 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[segments_3]
[junit4:junit4]   2> 16388 T3475 C254 P53200 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2
[junit4:junit4]   2> 16388 T3475 C254 P53200 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16388 T3475 C254 P53200 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/index.20130220020245671
[junit4:junit4]   2> 16388 T3475 C254 P53200 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty2/index
[junit4:junit4]   2> 16389 T3475 C254 P53200 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 16389 T3475 C254 P53200 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 16389 T3475 C254 P53200 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 16389 T3475 C254 P53200 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 16396 T3475 C254 P53200 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 16675 T3439 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16676 T3439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53205_xioj%2Fl",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53205/xioj/l"}
[junit4:junit4]   2> 16680 T3439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53200_xioj%2Fl",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53200/xioj/l"}
[junit4:junit4]   2> 16697 T3438 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> 16697 T3488 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> 16697 T3457 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> 16697 T3504 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> 16697 T3472 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> 16697 T3444 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> 17002 T3416 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:28083_xioj%2Fl
[junit4:junit4]   2> 17003 T3421 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cf6a00b4a000c type:delete cxid:0xb zxid:0x9d txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:28083_xioj%2Fl Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:28083_xioj%2Fl
[junit4:junit4]   2> 17004 T3416 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:28083_xioj%2Fl
[junit4:junit4]   2> 17017 T3444 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> 17017 T3438 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> 17018 T3488 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17018 T3457 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17018 T3504 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17017 T3472 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17018 T3457 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> 17018 T3472 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> 17019 T3444 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17018 T3488 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> 17018 T3504 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> 17020 T3438 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17030 T3507 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty4-1361347365020/collection1
[junit4:junit4]   2> 17031 T3507 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 17031 T3507 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 17031 T3507 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 17033 T3507 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty4-1361347365020/collection1/'
[junit4:junit4]   2> 17034 T3507 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty4-1361347365020/collection1/lib/README' to classloader
[junit4:junit4]   2> 17035 T3507 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty4-1361347365020/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 17111 T3507 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 17166 T3507 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 17266 T3507 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 17272 T3507 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 17877 T3507 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 17888 T3507 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 17893 T3507 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 17906 T3507 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 17910 T3507 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 17914 T3507 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 17915 T3507 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 17917 T3507 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty4-1361347365020/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/
[junit4:junit4]   2> 17917 T3507 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d762027
[junit4:junit4]   2> 17917 T3507 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 17918 T3507 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4 forceNew:false
[junit4:junit4]   2> 17919 T3507 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4
[junit4:junit4]   2> 17919 T3507 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index/
[junit4:junit4]   2> 17920 T3507 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 17921 T3507 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index forceNew:false
[junit4:junit4]   2> 17934 T3507 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@67f4d7d1; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 17935 T3507 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 17936 T3507 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index
[junit4:junit4]   2> 17938 T3507 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 17938 T3507 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 17939 T3507 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 17939 T3507 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 17940 T3507 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 17940 T3507 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 17940 T3507 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 17941 T3507 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 17942 T3507 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 17949 T3507 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 17955 T3507 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4
[junit4:junit4]   2> 17957 T3507 oass.SolrIndexSearcher.<init> Opening Searcher@621303b4 main
[junit4:junit4]   2> 17958 T3507 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 17958 T3507 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 17963 T3508 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@621303b4 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 17964 T3507 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 17965 T3507 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 18203 T3439 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18204 T3439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:28083_xioj%2Fl",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:28083/xioj/l"}
[junit4:junit4]   2> 18204 T3439 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4]   2> 18204 T3439 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 18223 T3488 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> 18223 T3504 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> 18223 T3438 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> 18223 T3444 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> 18223 T3457 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> 18223 T3472 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>  C255_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:53205_xioj%2Fl, base_url=http://127.0.0.1:53205/xioj/l}
[junit4:junit4]   2> 18713 T3491 C255 P53205 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:53194/xioj/l/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 18713 T3491 C255 P53205 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:53205/xioj/l START replicas=[http://127.0.0.1:53194/xioj/l/collection1/] nUpdates=100
[junit4:junit4]   2> 18714 T3491 C255 P53205 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 18714 T3491 C255 P53205 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 18714 T3491 C255 P53205 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 18714 T3491 C255 P53205 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 18714 T3491 C255 P53205 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 18715 T3491 C255 P53205 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:53194/xioj/l/collection1/. core=collection1
[junit4:junit4]   2> 18715 T3491 C255 P53205 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 18716 T3449 C256 P53194 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0 
[junit4:junit4]   2> 18730 T3452 C256 P53194 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 18736 T3452 C256 P53194 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@bebc341; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@bebc341; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   2> 18737 T3452 C256 P53194 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[segments_3]
[junit4:junit4]   2> 18737 T3452 C256 P53194 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1
[junit4:junit4]   2> 18738 T3452 C256 P53194 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18738 T3452 C256 P53194 /update {waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 8
[junit4:junit4]   2> 18739 T3491 C255 P53205 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 18739 T3491 C255 P53205 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 18741 T3451 C256 P53194 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 18742 T3491 C255 P53205 oash.SnapPuller.fetchLatestIndex Master's generation: 3
[junit4:junit4]   2> 18742 T3491 C255 P53205 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 18742 T3491 C255 P53205 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 18744 T3451 C256 P53194 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1
[junit4:junit4]   2> 18745 T3451 C256 P53194 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index
[junit4:junit4]   2> 18745 T3451 C256 P53194 REQ /replication {command=filelist&qt=/replication&wt=javabin&generation=3&version=2} status=0 QTime=1 
[junit4:junit4]   2> 18746 T3491 C255 P53205 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 18747 T3491 C255 P53205 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/index.20130220020248056 forceNew:false
[junit4:junit4]   2> 18747 T3491 C255 P53205 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3
[junit4:junit4]   2> 18748 T3491 C255 P53205 oash.SnapPuller.fetchLatestIndex Starting download to NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/index.20130220020248056 lockFactory=org.apache.lucene.store.NativeFSLockFactory@45e29095; maxCacheMB=48.0 maxMergeSizeMB=4.0) fullCopy=true
[junit4:junit4]   2> 18751 T3451 C256 P53194 REQ /replication {file=segments_3&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0 
[junit4:junit4]   2> 18752 T3491 C255 P53205 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/index
[junit4:junit4]   2> 18752 T3491 C255 P53205 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 18753 T3491 C255 P53205 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130220020248056
[junit4:junit4]   2> 18754 T3491 C255 P53205 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3
[junit4:junit4]   2> 18755 T3491 C255 P53205 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3
[junit4:junit4]   2> 18755 T3491 C255 P53205 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/index/ new=./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/index.20130220020248056
[junit4:junit4]   2> 18759 T3491 C255 P53205 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/index.20130220020248056 lockFactory=org.apache.lucene.store.NativeFSLockFactory@45e29095; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   2> 18759 T3491 C255 P53205 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[segments_3]
[junit4:junit4]   2> 18760 T3491 C255 P53205 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3
[junit4:junit4]   2> 18760 T3491 C255 P53205 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 18760 T3491 C255 P53205 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 18761 T3491 C255 P53205 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 18761 T3491 C255 P53205 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/index.20130220020248056
[junit4:junit4]   2> 18762 T3491 C255 P53205 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3
[junit4:junit4]   2> 18765 T3491 C255 P53205 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/index.20130220020248056 lockFactory=org.apache.lucene.store.NativeFSLockFactory@45e29095; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   2> 18766 T3491 C255 P53205 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[segments_3]
[junit4:junit4]   2> 18766 T3491 C255 P53205 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 18766 T3491 C255 P53205 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3
[junit4:junit4]   2> 18767 T3491 C255 P53205 oass.SolrIndexSearcher.<init> Opening Searcher@315936fa main
[junit4:junit4]   2> 18768 T3490 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@315936fa main{StandardDirectoryReader(segments_3:1:nrt)}
[junit4:junit4]   2> 18768 T3490 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/index
[junit4:junit4]   2> 18768 T3491 C255 P53205 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=false,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 18772 T3491 C255 P53205 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/index.20130220020248056 lockFactory=org.apache.lucene.store.NativeFSLockFactory@45e29095; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/index.20130220020248056 lockFactory=org.apache.lucene.store.NativeFSLockFactory@45e29095; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_4,generation=4,filenames=[segments_4]
[junit4:junit4]   2> 18772 T3491 C255 P53205 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[segments_4]
[junit4:junit4]   2> 18773 T3491 C255 P53205 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3
[junit4:junit4]   2> 18774 T3491 C255 P53205 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18774 T3491 C255 P53205 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/index.20130220020248056
[junit4:junit4]   2> 18774 T3491 C255 P53205 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty3/index
[junit4:junit4]   2> 18774 T3491 C255 P53205 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 18774 T3491 C255 P53205 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 18775 T3491 C255 P53205 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 18775 T3491 C255 P53205 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 18781 T3491 C255 P53205 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 18967 T3507 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 18967 T3507 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:28083/xioj/l collection:collection1 shard:shard1
[junit4:junit4]   2> 18970 T3507 oasc.ZkController.register We are http://127.0.0.1:28083/xioj/l/collection1/ and leader is http://127.0.0.1:53194/xioj/l/collection1/
[junit4:junit4]   2> 18970 T3507 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:28083/xioj/l
[junit4:junit4]   2> 18970 T3507 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 18970 T3507 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C257 name=collection1 org.apache.solr.core.SolrCore@2c717166 url=http://127.0.0.1:28083/xioj/l/collection1 node=127.0.0.1:28083_xioj%2Fl C257_STATE=coll:collection1 core:collection1 props:{shard=null, roles=null, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:28083_xioj%2Fl, base_url=http://127.0.0.1:28083/xioj/l}
[junit4:junit4]   2> 18971 T3511 C257 P28083 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 18972 T3507 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18972 T3511 C257 P28083 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 18972 T3511 C257 P28083 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 18972 T3511 C257 P28083 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 18972 T3416 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 18973 T3416 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 18973 T3416 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 18974 T3511 C257 P28083 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 18988 T3416 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18989 T3416 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt
[junit4:junit4]   2> 18989 T3416 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4:junit4]   2> 18989 T3416 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19727 T3439 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19728 T3439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53205_xioj%2Fl",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53205/xioj/l"}
[junit4:junit4]   2> 19757 T3439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:28083_xioj%2Fl",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:28083/xioj/l"}
[junit4:junit4]   2> 19770 T3438 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> 19770 T3488 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> 19770 T3504 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> 19770 T3472 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> 19770 T3457 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> 19770 T3444 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> 19991 T3416 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20993 T3416 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C257_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:28083_xioj%2Fl, base_url=http://127.0.0.1:28083/xioj/l}
[junit4:junit4]   2> 21991 T3511 C257 P28083 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:53194/xioj/l/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 21991 T3511 C257 P28083 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:28083/xioj/l START replicas=[http://127.0.0.1:53194/xioj/l/collection1/] nUpdates=100
[junit4:junit4]   2> 21992 T3511 C257 P28083 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 21992 T3511 C257 P28083 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 21992 T3511 C257 P28083 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 21993 T3511 C257 P28083 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 21993 T3511 C257 P28083 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 21993 T3511 C257 P28083 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:53194/xioj/l/collection1/. core=collection1
[junit4:junit4]   2> 21993 T3511 C257 P28083 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 21994 T3449 C256 P53194 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0 
[junit4:junit4]   2> 21995 T3416 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22003 T3447 C256 P53194 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 22008 T3447 C256 P53194 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=3
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@bebc341; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@bebc341; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@bebc341; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_4,generation=4,filenames=[segments_4]
[junit4:junit4]   2> 22008 T3447 C256 P53194 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[segments_4]
[junit4:junit4]   2> 22009 T3447 C256 P53194 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1
[junit4:junit4]   2> 22009 T3447 C256 P53194 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 22010 T3447 C256 P53194 /update {waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 7
[junit4:junit4]   2> 22011 T3511 C257 P28083 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 22011 T3511 C257 P28083 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 22013 T3451 C256 P53194 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 22014 T3511 C257 P28083 oash.SnapPuller.fetchLatestIndex Master's generation: 4
[junit4:junit4]   2> 22014 T3511 C257 P28083 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 22014 T3511 C257 P28083 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 22017 T3451 C256 P53194 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1
[junit4:junit4]   2> 22018 T3451 C256 P53194 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index
[junit4:junit4]   2> 22018 T3451 C256 P53194 REQ /replication {command=filelist&qt=/replication&wt=javabin&generation=4&version=2} status=0 QTime=1 
[junit4:junit4]   2> 22019 T3511 C257 P28083 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 22020 T3511 C257 P28083 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index.20130220020251329 forceNew:false
[junit4:junit4]   2> 22020 T3511 C257 P28083 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4
[junit4:junit4]   2> 22021 T3511 C257 P28083 oash.SnapPuller.fetchLatestIndex Starting download to NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index.20130220020251329 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6d81dd3c; maxCacheMB=48.0 maxMergeSizeMB=4.0) fullCopy=true
[junit4:junit4]   2> 22024 T3451 C256 P53194 REQ /replication {file=segments_4&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0 
[junit4:junit4]   2> 22025 T3511 C257 P28083 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index
[junit4:junit4]   2> 22026 T3511 C257 P28083 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 22026 T3511 C257 P28083 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130220020251329
[junit4:junit4]   2> 22027 T3511 C257 P28083 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4
[junit4:junit4]   2> 22028 T3511 C257 P28083 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4
[junit4:junit4]   2> 22028 T3511 C257 P28083 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index/ new=./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index.20130220020251329
[junit4:junit4]   2> 22032 T3511 C257 P28083 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index.20130220020251329 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6d81dd3c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_4,generation=4,filenames=[segments_4]
[junit4:junit4]   2> 22032 T3511 C257 P28083 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[segments_4]
[junit4:junit4]   2> 22033 T3511 C257 P28083 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4
[junit4:junit4]   2> 22033 T3511 C257 P28083 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 22033 T3511 C257 P28083 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 22034 T3511 C257 P28083 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 22034 T3511 C257 P28083 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index.20130220020251329
[junit4:junit4]   2> 22035 T3511 C257 P28083 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4
[junit4:junit4]   2> 22038 T3511 C257 P28083 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index.20130220020251329 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6d81dd3c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_4,generation=4,filenames=[segments_4]
[junit4:junit4]   2> 22039 T3511 C257 P28083 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[segments_4]
[junit4:junit4]   2> 22039 T3511 C257 P28083 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 22039 T3511 C257 P28083 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4
[junit4:junit4]   2> 22040 T3511 C257 P28083 oass.SolrIndexSearcher.<init> Opening Searcher@4352d822 main
[junit4:junit4]   2> 22041 T3508 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4352d822 main{StandardDirectoryReader(segments_4:1:nrt)}
[junit4:junit4]   2> 22041 T3508 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index
[junit4:junit4]   2> 22041 T3511 C257 P28083 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=false,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 22045 T3511 C257 P28083 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index.20130220020251329 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6d81dd3c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_4,generation=4,filenames=[segments_4]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index.20130220020251329 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6d81dd3c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_5,generation=5,filenames=[segments_5]
[junit4:junit4]   2> 22045 T3511 C257 P28083 oasc.SolrDeletionPolicy.updateCommits newest commit = 5[segments_5]
[junit4:junit4]   2> 22047 T3511 C257 P28083 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4
[junit4:junit4]   2> 22047 T3511 C257 P28083 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 22047 T3511 C257 P28083 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index.20130220020251329
[junit4:junit4]   2> 22047 T3511 C257 P28083 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index
[junit4:junit4]   2> 22047 T3511 C257 P28083 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 22048 T3511 C257 P28083 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 22048 T3511 C257 P28083 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 22048 T3511 C257 P28083 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 22055 T3511 C257 P28083 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 22785 T3439 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22786 T3439 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:28083_xioj%2Fl",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:28083/xioj/l"}
[junit4:junit4]   2> 22803 T3504 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> 22803 T3488 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> 22803 T3438 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> 22803 T3457 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> 22803 T3472 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> 22803 T3444 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> 22997 T3416 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22998 T3416 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4]   2> ASYNC  NEW_CORE C258 name=collection1 org.apache.solr.core.SolrCore@4727493c url=http://127.0.0.1:53190/xioj/l/collection1 node=127.0.0.1:53190_xioj%2Fl C258_STATE=coll:control_collection core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:53190_xioj%2Fl, base_url=http://127.0.0.1:53190/xioj/l, leader=true}
[junit4:junit4]   2> 23008 T3428 C258 P53190 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 23009 T3428 C258 P53190 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/control/data
[junit4:junit4]   2> 23014 T3428 C258 P53190 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d4a00ff; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 23014 T3428 C258 P53190 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 23029 T3428 C258 P53190 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d4a00ff; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d4a00ff; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 23030 T3428 C258 P53190 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 23031 T3428 C258 P53190 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/control/data
[junit4:junit4]   2> 23034 T3428 C258 P53190 oass.SolrIndexSearcher.<init> Opening Searcher@72f23851 main
[junit4:junit4]   2> 23034 T3428 C258 P53190 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 23035 T3442 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@72f23851 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 23035 T3442 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/control/data/index
[junit4:junit4]   2> 23036 T3428 C258 P53190 /update {waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 28
[junit4:junit4]   2> 23046 T3450 C256 P53194 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 23056 T3450 C256 P53194 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=4
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@bebc341; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@bebc341; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@bebc341; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_4,generation=4,filenames=[segments_4]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@bebc341; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_5,generation=5,filenames=[segments_5]
[junit4:junit4]   2> 23057 T3450 C256 P53194 oasc.SolrDeletionPolicy.updateCommits newest commit = 5[segments_5]
[junit4:junit4]   2> 23058 T3450 C256 P53194 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1
[junit4:junit4]   2> 23059 T3450 C256 P53194 oass.SolrIndexSearcher.<init> Opening Searcher@165e603f main
[junit4:junit4]   2> 23059 T3450 C256 P53194 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index
[junit4:junit4]   2> 23060 T3450 C256 P53194 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 23060 T3459 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@165e603f main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 23061 T3459 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty1/index
[junit4:junit4]   2> 23061 T3450 C256 P53194 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:53200/xioj/l/collection1/, StdNode: http://127.0.0.1:53205/xioj/l/collection1/, StdNode: http://127.0.0.1:28083/xioj/l/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4]   2>  C255_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:53205_xioj%2Fl, base_url=http://127.0.0.1:53205/xioj/l}
[junit4:junit4]   2> 23075 T3478 C255 P53205 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2>  C257_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:28083_xioj%2Fl, base_url=http://127.0.0.1:28083/xioj/l}
[junit4:junit4]   2> 23075 T3494 C257 P28083 oasu.DirectUpdateHandler2.

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

Closer
[junit4:junit4]   2> 161207 T3504 C257 P28083 oasu.TransactionLog.forceClose SEVERE Error: Forcing close of tlog{file=./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/tlog/tlog.0000000000000000005 refcount=1}
[junit4:junit4]   2> 161210 T3504 C257 P28083 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index.20130220020251329
[junit4:junit4]   2> 161211 T3504 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 161212 T3504 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index.20130220020251329
[junit4:junit4]   2> 161212 T3504 oasc.CachingDirectoryFactory.close Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index.20130220020251329
[junit4:junit4]   2> 161212 T3504 oash.SnapPuller$2.preClose removing old index files NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@67f4d7d1; maxCacheMB=48.0 maxMergeSizeMB=4.0)
[junit4:junit4]   2> 161213 T3504 oasc.CachingDirectoryFactory.closeDirectory Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index.20130220020251329
[junit4:junit4]   2> 161213 T3504 oash.SnapPuller$2.postClose removing old index directory NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@67f4d7d1; maxCacheMB=48.0 maxMergeSizeMB=4.0)
[junit4:junit4]   2> 161214 T3504 oasc.CachingDirectoryFactory.close Closing directory when closing factory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4
[junit4:junit4]   2> 161214 T3504 oasc.CachingDirectoryFactory.closeDirectory Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4
[junit4:junit4]   2> 161214 T3504 oasc.CachingDirectoryFactory.close Closing directory when closing factory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index
[junit4:junit4]   2> 161214 T3504 oasc.CachingDirectoryFactory.closeDirectory Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1361347349315/jetty4/index
[junit4:junit4]   2> 161215 T3504 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 161215 T3504 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> 161215 T3504 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 161215 T3504 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> 161216 T3504 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> NOTE: test params are: codec=Lucene41, sim=DefaultSimilarity, locale=ar_QA, timezone=America/Guatemala
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=3,free=73988728,total=327614464
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestArbitraryIndexDir, SignatureUpdateProcessorFactoryTest, DirectUpdateHandlerTest, TestReversedWildcardFilterFactory, TestDocumentBuilder, TestStressLucene, TestCharFilters, TestUpdate, SoftAutoCommitTest, TestPluginEnable, DOMUtilTest, ExternalFileFieldSortTest, TestPropInject, IndexSchemaTest, BasicFunctionalityTest, SynonymTokenizerTest, ClusterStateTest, PrimitiveFieldTypeTest, TestLazyCores, TestLRUCache, BasicDistributedZk2Test, RAMDirectoryFactoryTest, RecoveryZkTest, MultiTermTest, TestCodecSupport, ReturnFieldsTest, TestOmitPositions, DocumentAnalysisRequestHandlerTest, TestSolrCoreProperties, SolrCoreTest, EchoParamsTest, TestReplicationHandler, BadIndexSchemaTest, PolyFieldTest, TestSurroundQueryParser, FieldMutatingUpdateProcessorTest, TestSolrXMLSerializer, DebugComponentTest, SuggesterTSTTest, SolrIndexSplitterTest, UpdateParamsTest, ZkNodePropsTest, LukeRequestHandlerTest, TestDistributedSearch, TestQueryUtils, QueryParsingTest, TestCSVResponseWriter, TestRemoteStreaming, TestBM25SimilarityFactory, TestJmxIntegration, PeerSyncTest, AnalysisAfterCoreReloadTest, XsltUpdateRequestHandlerTest, DistributedQueryElevationComponentTest, ShowFileRequestHandlerTest, TestDFRSimilarityFactory, FullSolrCloudDistribCmdsTest, PingRequestHandlerTest, TestDistributedGrouping, TestRecovery, OutputWriterTest, OverseerTest, SpellCheckComponentTest, LeaderElectionTest, DistributedSpellCheckComponentTest, TestRealTimeGet, SpellCheckCollatorTest, AutoCommitTest, BasicZkTest, ZkSolrClientTest, WordBreakSolrSpellCheckerTest, TestHashPartitioner, StatsComponentTest, TestMultiCoreConfBootstrap, SimpleFacetsTest, TestSort, TestGroupingSearch, DirectSolrSpellCheckerTest, ConvertedLegacyTest, QueryElevationComponentTest, SortByFunctionTest, TestBinaryResponseWriter, SampleTest, HighlighterTest, TestIndexSearcher, CoreAdminHandlerTest, TestFunctionQuery, TestTrie, DirectSolrConnectionTest, CacheHeaderTest, QueryEqualityTest, TestCSVLoader, SpatialFilterTest, MoreLikeThisHandlerTest, DocumentBuilderTest, CurrencyFieldTest, DisMaxRequestHandlerTest, TermsComponentTest, DistanceFunctionTest, SolrInfoMBeanTest, MinimalSchemaTest, StandardRequestHandlerTest, TestQueryTypes, XmlUpdateRequestHandlerTest, TermVectorComponentTest, JsonLoaderTest, IndexSchemaRuntimeFieldTest, TestSolrQueryParser, TestValueSourceCache, FastVectorHighlighterTest, JSONWriterTest, RequiredFieldsTest, SuggesterFSTTest, LoggingHandlerTest, SolrCmdDistributorTest, UniqFieldsUpdateProcessorFactoryTest, SuggesterTest, CSVRequestHandlerTest, TestFoldingMultitermQuery, SolrCoreCheckLockOnStartupTest, TestSolrDeletionPolicy1, NoCacheHeaderTest, TestBinaryField, TestPropInjectDefaults, DefaultValueUpdateProcessorTest, TestXIncludeConfig, TestLFUCache, TestCollationField, IndexReaderFactoryTest, TestJmxMonitoredMap, TestPerFieldSimilarity, TestIBSimilarityFactory, URLClassifyProcessorTest, PluginInfoTest, OpenExchangeRatesOrgProviderTest, FileUtilsTest, SpellingQueryConverterTest, UUIDFieldTest, CollectionsAPIDistributedZkTest, SliceStateTest, SliceStateUpdateTest, SyncSliceTest]
[junit4:junit4] Completed on J1 in 161.72s, 1 test, 1 failure <<< FAILURES!

[...truncated 10 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:381: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:361: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build.xml:183: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/common-build.xml:447: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:1202: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:865: There were test failures: 255 suites, 1055 tests, 1 failure, 22 ignored (4 assumptions)

Total time: 43 minutes 56 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