You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/03/01 22:36:35 UTC
[JENKINS] Lucene-Solr-Tests-trunk-Java6 - Build # 15966 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java6/15966/
1 tests failed.
FAILED: org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch
Error Message:
No registered leader was found, collection:collection1 slice:shard1
Stack Trace:
org.apache.solr.common.SolrException: No registered leader was found, collection:collection1 slice:shard1
at __randomizedtesting.SeedInfo.seed([425EB2AD4568CA23:C3B83CB53237AA1F]:0)
at org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:430)
at org.apache.solr.cloud.BasicDistributedZk2Test.brindDownShardIndexSomeDocsAndRecover(BasicDistributedZk2Test.java:295)
at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:116)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java: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 8859 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4] 2> 0 T3429 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 3 T3429 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362173479482
[junit4:junit4] 2> 4 T3429 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 4 T3430 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 6 T3430 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4] 2> 6 T3430 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4] 2> 6 T3430 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4] 2> 7 T3430 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> 7 T3430 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4] 2> 105 T3429 oasc.ZkTestServer.run start zk server on port:27707
[junit4:junit4] 2> 105 T3429 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:27707 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@7d41a206
[junit4:junit4] 2> 106 T3429 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 106 T3435 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:27707. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 107 T3435 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:27707, initiating session
[junit4:junit4] 2> 107 T3431 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:27708
[junit4:junit4] 2> 107 T3431 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:27708
[junit4:junit4] 2> 108 T3433 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4] 2> 242 T3433 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d27ddca3f0000 with negotiated timeout 10000 for client /140.211.11.196:27708
[junit4:junit4] 2> 242 T3435 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:27707, sessionid = 0x13d27ddca3f0000, negotiated timeout = 10000
[junit4:junit4] 2> 242 T3436 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7d41a206 name:ZooKeeperConnection Watcher:127.0.0.1:27707 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 242 T3429 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 243 T3429 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 249 T3434 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d27ddca3f0000
[junit4:junit4] 2> 250 T3436 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 250 T3431 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:27708 which had sessionid 0x13d27ddca3f0000
[junit4:junit4] 2> 250 T3429 oaz.ZooKeeper.close Session: 0x13d27ddca3f0000 closed
[junit4:junit4] 2> 251 T3429 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:27707/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@2d90e7b6
[junit4:junit4] 2> 252 T3429 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 252 T3437 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:27707. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 252 T3437 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:27707, initiating session
[junit4:junit4] 2> 253 T3431 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:27709
[junit4:junit4] 2> 253 T3431 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:27709
[junit4:junit4] 2> 260 T3433 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d27ddca3f0001 with negotiated timeout 10000 for client /140.211.11.196:27709
[junit4:junit4] 2> 260 T3437 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:27707, sessionid = 0x13d27ddca3f0001, negotiated timeout = 10000
[junit4:junit4] 2> 261 T3438 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2d90e7b6 name:ZooKeeperConnection Watcher:127.0.0.1:27707/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 261 T3429 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 261 T3429 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 271 T3429 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 274 T3429 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 276 T3429 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 285 T3429 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 286 T3429 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 303 T3429 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 304 T3429 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 407 T3429 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 408 T3429 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 410 T3429 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 411 T3429 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 425 T3429 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 425 T3429 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 428 T3429 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 429 T3429 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 432 T3429 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 432 T3429 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 435 T3429 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 435 T3429 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 443 T3429 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 443 T3429 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 446 T3434 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d27ddca3f0001
[junit4:junit4] 2> 447 T3438 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 447 T3429 oaz.ZooKeeper.close Session: 0x13d27ddca3f0001 closed
[junit4:junit4] 2> 447 T3431 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:27709 which had sessionid 0x13d27ddca3f0001
[junit4:junit4] 2> 563 T3429 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 566 T3429 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:27710
[junit4:junit4] 2> 567 T3429 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 567 T3429 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 568 T3429 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362173479925
[junit4:junit4] 2> 568 T3429 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362173479925/solr.xml
[junit4:junit4] 2> 568 T3429 oasc.CoreContainer.<init> New CoreContainer 1708812936
[junit4:junit4] 2> 569 T3429 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362173479925/'
[junit4:junit4] 2> 569 T3429 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362173479925/'
[junit4:junit4] 2> 600 T3429 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 600 T3429 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 601 T3429 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 601 T3429 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 601 T3429 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 601 T3429 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 602 T3429 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 602 T3429 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 602 T3429 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 603 T3429 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 616 T3429 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 629 T3429 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:27707/solr
[junit4:junit4] 2> 629 T3429 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 629 T3429 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:27707 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@79d6df69
[junit4:junit4] 2> 630 T3429 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 630 T3448 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:27707. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 631 T3448 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:27707, initiating session
[junit4:junit4] 2> 631 T3431 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:27711
[junit4:junit4] 2> 631 T3431 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:27711
[junit4:junit4] 2> 633 T3433 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d27ddca3f0002 with negotiated timeout 20000 for client /140.211.11.196:27711
[junit4:junit4] 2> 633 T3448 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:27707, sessionid = 0x13d27ddca3f0002, negotiated timeout = 20000
[junit4:junit4] 2> 633 T3449 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@79d6df69 name:ZooKeeperConnection Watcher:127.0.0.1:27707 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 634 T3429 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 635 T3434 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d27ddca3f0002
[junit4:junit4] 2> 644 T3449 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 644 T3431 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:27711 which had sessionid 0x13d27ddca3f0002
[junit4:junit4] 2> 644 T3429 oaz.ZooKeeper.close Session: 0x13d27ddca3f0002 closed
[junit4:junit4] 2> 644 T3429 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 652 T3429 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:27707/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@62afbd37
[junit4:junit4] 2> 652 T3429 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 653 T3450 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:27707. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 653 T3450 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:27707, initiating session
[junit4:junit4] 2> 653 T3431 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:27712
[junit4:junit4] 2> 654 T3431 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:27712
[junit4:junit4] 2> 655 T3433 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d27ddca3f0003 with negotiated timeout 20000 for client /140.211.11.196:27712
[junit4:junit4] 2> 655 T3450 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:27707, sessionid = 0x13d27ddca3f0003, negotiated timeout = 20000
[junit4:junit4] 2> 655 T3451 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@62afbd37 name:ZooKeeperConnection Watcher:127.0.0.1:27707/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 655 T3429 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 657 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 659 T3429 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 669 T3429 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:27710_
[junit4:junit4] 2> 670 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:27710_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:27710_
[junit4:junit4] 2> 671 T3429 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:27710_
[junit4:junit4] 2> 674 T3429 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 685 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0003 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> 692 T3429 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 695 T3429 oasc.Overseer.start Overseer (id=89271401151660035-127.0.0.1:27710_-n_0000000000) starting
[junit4:junit4] 2> 695 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 697 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 706 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 707 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 713 T3453 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 713 T3429 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 722 T3429 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 724 T3452 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 729 T3454 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362173479925/collection1
[junit4:junit4] 2> 729 T3454 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 729 T3454 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 730 T3454 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 731 T3454 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362173479925/collection1/'
[junit4:junit4] 2> 731 T3454 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362173479925/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 732 T3454 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362173479925/collection1/lib/README' to classloader
[junit4:junit4] 2> 762 T3454 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 799 T3454 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 900 T3454 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 907 T3454 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 1776 T3454 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1785 T3454 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1788 T3454 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1798 T3454 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1802 T3454 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1806 T3454 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1807 T3454 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1807 T3454 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 1807 T3454 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1808 T3454 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1808 T3454 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 1808 T3454 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1362173479925/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/control/data/
[junit4:junit4] 2> 1809 T3454 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1414627a
[junit4:junit4] 2> 1809 T3454 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1810 T3454 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/control/data forceNew:false
[junit4:junit4] 2> 1810 T3454 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/control/data
[junit4:junit4] 2> 1810 T3454 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/control/data/index/
[junit4:junit4] 2> 1811 T3454 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1811 T3454 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/control/data/index forceNew:false
[junit4:junit4] 2> 1813 T3454 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@e9560a lockFactory=org.apache.lucene.store.NativeFSLockFactory@2fcd9aaa; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 1813 T3454 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 1814 T3454 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/control/data/index
[junit4:junit4] 2> 1816 T3454 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1816 T3454 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1816 T3454 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1817 T3454 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1817 T3454 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1817 T3454 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1817 T3454 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1818 T3454 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1818 T3454 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1823 T3454 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1828 T3454 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/control/data
[junit4:junit4] 2> 1828 T3454 oass.SolrIndexSearcher.<init> Opening Searcher@142c2ae7 main
[junit4:junit4] 2> 1829 T3454 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/control/data/tlog
[junit4:junit4] 2> 1829 T3454 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1829 T3454 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1832 T3454 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/control/data
[junit4:junit4] 2> 1832 T3455 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@142c2ae7 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1833 T3454 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1833 T3454 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1834 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0003 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> 2227 T3452 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2228 T3452 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "node_name":"127.0.0.1:27710_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:27710"}
[junit4:junit4] 2> 2228 T3452 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 2228 T3452 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 2229 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0003 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> 2256 T3451 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> 2852 T3454 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2852 T3454 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:27710 collection:control_collection shard:shard1
[junit4:junit4] 2> 2853 T3454 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2894 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0003 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> 2895 T3454 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2895 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0003 type:create cxid:0x73 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 2904 T3454 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2905 T3454 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2905 T3454 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:27710/collection1/
[junit4:junit4] 2> 2905 T3454 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2905 T3454 oasc.SyncStrategy.syncToMe http://127.0.0.1:27710/collection1/ has no replicas
[junit4:junit4] 2> 2906 T3454 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:27710/collection1/
[junit4:junit4] 2> 2906 T3454 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 2909 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0003 type:create cxid:0x7d zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3760 T3452 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3803 T3451 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> 3829 T3454 oasc.ZkController.register We are http://127.0.0.1:27710/collection1/ and leader is http://127.0.0.1:27710/collection1/
[junit4:junit4] 2> 3829 T3454 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:27710
[junit4:junit4] 2> 3829 T3454 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 3829 T3454 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 3829 T3454 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 3831 T3454 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3832 T3429 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1
[junit4:junit4] 2> 3832 T3429 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 3833 T3429 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 3847 T3429 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 3848 T3429 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:27707/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@4468a394
[junit4:junit4] 2> 3849 T3429 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3849 T3456 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:27707. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 3850 T3456 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:27707, initiating session
[junit4:junit4] 2> 3850 T3431 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:27713
[junit4:junit4] 2> 3850 T3431 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:27713
[junit4:junit4] 2> 3851 T3433 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d27ddca3f0004 with negotiated timeout 10000 for client /140.211.11.196:27713
[junit4:junit4] 2> 3851 T3456 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:27707, sessionid = 0x13d27ddca3f0004, negotiated timeout = 10000
[junit4:junit4] 2> 3852 T3457 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4468a394 name:ZooKeeperConnection Watcher:127.0.0.1:27707/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3852 T3429 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3853 T3429 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 3854 T3429 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 4029 T3429 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 4032 T3429 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:27714
[junit4:junit4] 2> 4032 T3429 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 4033 T3429 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 4033 T3429 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362173483332
[junit4:junit4] 2> 4034 T3429 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362173483332/solr.xml
[junit4:junit4] 2> 4034 T3429 oasc.CoreContainer.<init> New CoreContainer 642996208
[junit4:junit4] 2> 4035 T3429 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362173483332/'
[junit4:junit4] 2> 4035 T3429 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362173483332/'
[junit4:junit4] 2> 4081 T3429 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 4081 T3429 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 4082 T3429 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 4082 T3429 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 4082 T3429 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 4083 T3429 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 4083 T3429 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 4084 T3429 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 4084 T3429 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 4085 T3429 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 4104 T3429 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 4122 T3429 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:27707/solr
[junit4:junit4] 2> 4123 T3429 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 4123 T3429 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:27707 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@7e0cb8ea
[junit4:junit4] 2> 4124 T3429 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 4125 T3467 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:27707. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 4125 T3467 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:27707, initiating session
[junit4:junit4] 2> 4125 T3431 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:27715
[junit4:junit4] 2> 4126 T3431 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:27715
[junit4:junit4] 2> 4128 T3433 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d27ddca3f0005 with negotiated timeout 20000 for client /140.211.11.196:27715
[junit4:junit4] 2> 4128 T3467 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:27707, sessionid = 0x13d27ddca3f0005, negotiated timeout = 20000
[junit4:junit4] 2> 4128 T3468 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7e0cb8ea name:ZooKeeperConnection Watcher:127.0.0.1:27707 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 4128 T3429 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 4129 T3434 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d27ddca3f0005
[junit4:junit4] 2> 4146 T3468 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 4146 T3431 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:27715 which had sessionid 0x13d27ddca3f0005
[junit4:junit4] 2> 4145 T3429 oaz.ZooKeeper.close Session: 0x13d27ddca3f0005 closed
[junit4:junit4] 2> 4146 T3429 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 4156 T3429 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:27707/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@5e03cb03
[junit4:junit4] 2> 4157 T3429 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 4157 T3469 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:27707. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 4158 T3469 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:27707, initiating session
[junit4:junit4] 2> 4158 T3431 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:27716
[junit4:junit4] 2> 4158 T3431 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:27716
[junit4:junit4] 2> 4159 T3433 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d27ddca3f0006 with negotiated timeout 20000 for client /140.211.11.196:27716
[junit4:junit4] 2> 4159 T3469 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:27707, sessionid = 0x13d27ddca3f0006, negotiated timeout = 20000
[junit4:junit4] 2> 4160 T3470 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e03cb03 name:ZooKeeperConnection Watcher:127.0.0.1:27707/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 4160 T3429 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 4161 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0006 type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 4167 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0006 type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 4168 T3429 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 5171 T3429 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:27714_
[junit4:junit4] 2> 5172 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0006 type:delete cxid:0x9 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:27714_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:27714_
[junit4:junit4] 2> 5175 T3429 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:27714_
[junit4:junit4] 2> 5177 T3451 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> 5178 T3470 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 5178 T3457 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 5178 T3451 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 5198 T3471 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362173483332/collection1
[junit4:junit4] 2> 5198 T3471 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 5198 T3471 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 5199 T3471 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 5200 T3471 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362173483332/collection1/'
[junit4:junit4] 2> 5201 T3471 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362173483332/collection1/lib/README' to classloader
[junit4:junit4] 2> 5201 T3471 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362173483332/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 5246 T3471 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 5301 T3471 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 5317 T3452 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 5318 T3452 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "node_name":"127.0.0.1:27710_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:27710"}
[junit4:junit4] 2> 5331 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> 5331 T3451 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> 5401 T3471 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 5401 T3470 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> 5411 T3471 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 5998 T3471 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 6008 T3471 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 6012 T3471 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 6025 T3471 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 6030 T3471 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 6034 T3471 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 6035 T3471 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 6036 T3471 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 6036 T3471 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 6037 T3471 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 6037 T3471 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 6037 T3471 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362173483332/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty1/
[junit4:junit4] 2> 6038 T3471 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1414627a
[junit4:junit4] 2> 6038 T3471 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 6039 T3471 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty1 forceNew:false
[junit4:junit4] 2> 6039 T3471 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty1
[junit4:junit4] 2> 6039 T3471 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty1/index/
[junit4:junit4] 2> 6040 T3471 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 6040 T3471 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty1/index forceNew:false
[junit4:junit4] 2> 6043 T3471 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@41afc692 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b7ffabb; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 6043 T3471 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 6044 T3471 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty1/index
[junit4:junit4] 2> 6045 T3471 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 6046 T3471 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 6046 T3471 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 6047 T3471 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 6047 T3471 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 6047 T3471 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 6048 T3471 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 6048 T3471 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 6048 T3471 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 6055 T3471 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 6061 T3471 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty1
[junit4:junit4] 2> 6061 T3471 oass.SolrIndexSearcher.<init> Opening Searcher@2ca48b2b main
[junit4:junit4] 2> 6062 T3471 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty1/tlog
[junit4:junit4] 2> 6062 T3471 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 6063 T3471 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 6066 T3472 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2ca48b2b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 6068 T3471 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 6068 T3471 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 6835 T3452 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 6836 T3452 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "numShards":"2",
[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:27714_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:27714"}
[junit4:junit4] 2> 6836 T3452 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 6836 T3452 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 6851 T3451 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> 6851 T3470 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> 6851 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> 7071 T3471 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 7071 T3471 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:27714 collection:collection1 shard:shard1
[junit4:junit4] 2> 7072 T3471 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 7162 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0006 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> 7186 T3471 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 7186 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0006 type:create cxid:0x47 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 7215 T3471 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 7215 T3471 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 7215 T3471 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:27714/collection1/
[junit4:junit4] 2> 7215 T3471 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 7215 T3471 oasc.SyncStrategy.syncToMe http://127.0.0.1:27714/collection1/ has no replicas
[junit4:junit4] 2> 7216 T3471 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:27714/collection1/
[junit4:junit4] 2> 7216 T3471 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 7248 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0006 type:create cxid:0x51 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8355 T3452 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8377 T3470 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> 8377 T3451 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> 8377 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> 8423 T3471 oasc.ZkController.register We are http://127.0.0.1:27714/collection1/ and leader is http://127.0.0.1:27714/collection1/
[junit4:junit4] 2> 8423 T3471 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:27714
[junit4:junit4] 2> 8423 T3471 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 8423 T3471 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 8423 T3471 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 8425 T3471 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8426 T3429 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1
[junit4:junit4] 2> 8426 T3429 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 8427 T3429 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 8611 T3429 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 8614 T3429 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:27717
[junit4:junit4] 2> 8614 T3429 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 8615 T3429 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 8615 T3429 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362173487919
[junit4:junit4] 2> 8616 T3429 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362173487919/solr.xml
[junit4:junit4] 2> 8616 T3429 oasc.CoreContainer.<init> New CoreContainer 1961772723
[junit4:junit4] 2> 8617 T3429 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362173487919/'
[junit4:junit4] 2> 8617 T3429 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362173487919/'
[junit4:junit4] 2> 8662 T3429 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 8663 T3429 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 8663 T3429 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 8664 T3429 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 8664 T3429 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 8664 T3429 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 8665 T3429 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 8665 T3429 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 8666 T3429 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 8666 T3429 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 8687 T3429 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 8705 T3429 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:27707/solr
[junit4:junit4] 2> 8705 T3429 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 8706 T3429 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:27707 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@6958998f
[junit4:junit4] 2> 8707 T3429 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8707 T3482 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:27707. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 8708 T3482 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:27707, initiating session
[junit4:junit4] 2> 8708 T3431 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:27718
[junit4:junit4] 2> 8708 T3431 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:27718
[junit4:junit4] 2> 8746 T3433 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d27ddca3f0007 with negotiated timeout 20000 for client /140.211.11.196:27718
[junit4:junit4] 2> 8746 T3482 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:27707, sessionid = 0x13d27ddca3f0007, negotiated timeout = 20000
[junit4:junit4] 2> 8746 T3483 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6958998f name:ZooKeeperConnection Watcher:127.0.0.1:27707 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8747 T3429 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8748 T3434 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d27ddca3f0007
[junit4:junit4] 2> 8760 T3483 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 8760 T3431 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:27718 which had sessionid 0x13d27ddca3f0007
[junit4:junit4] 2> 8760 T3429 oaz.ZooKeeper.close Session: 0x13d27ddca3f0007 closed
[junit4:junit4] 2> 8760 T3429 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 8772 T3429 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:27707/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@51bd6aca
[junit4:junit4] 2> 8773 T3429 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8773 T3484 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:27707. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 8774 T3484 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:27707, initiating session
[junit4:junit4] 2> 8774 T3431 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:27719
[junit4:junit4] 2> 8774 T3431 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:27719
[junit4:junit4] 2> 8775 T3433 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d27ddca3f0008 with negotiated timeout 20000 for client /140.211.11.196:27719
[junit4:junit4] 2> 8775 T3484 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:27707, sessionid = 0x13d27ddca3f0008, negotiated timeout = 20000
[junit4:junit4] 2> 8775 T3485 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51bd6aca name:ZooKeeperConnection Watcher:127.0.0.1:27707/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8776 T3429 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8777 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0008 type:create cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8778 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0008 type:create cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8780 T3429 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 9782 T3429 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:27717_
[junit4:junit4] 2> 9783 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0008 type:delete cxid:0x9 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:27717_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:27717_
[junit4:junit4] 2> 9786 T3429 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:27717_
[junit4:junit4] 2> 9788 T3451 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> 9788 T3457 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> 9788 T3485 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9789 T3470 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9789 T3470 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> 9789 T3457 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9789 T3451 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9796 T3486 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362173487919/collection1
[junit4:junit4] 2> 9796 T3486 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 9797 T3486 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 9797 T3486 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 9798 T3486 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362173487919/collection1/'
[junit4:junit4] 2> 9799 T3486 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362173487919/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 9800 T3486 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362173487919/collection1/lib/README' to classloader
[junit4:junit4] 2> 9844 T3486 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 9889 T3452 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 9890 T3452 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "numShards":"2",
[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:27714_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:27714"}
[junit4:junit4] 2> 9899 T3486 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 9903 T3485 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> 9903 T3470 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> 9903 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> 9903 T3486 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 9903 T3451 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> 9913 T3486 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 10496 T3486 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 10507 T3486 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 10511 T3486 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 10523 T3486 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 10528 T3486 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 10532 T3486 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 10533 T3486 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 10533 T3486 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 10533 T3486 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 10534 T3486 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 10534 T3486 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 10535 T3486 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1362173487919/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty2/
[junit4:junit4] 2> 10535 T3486 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1414627a
[junit4:junit4] 2> 10535 T3486 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 10536 T3486 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty2 forceNew:false
[junit4:junit4] 2> 10536 T3486 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty2
[junit4:junit4] 2> 10536 T3486 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty2/index/
[junit4:junit4] 2> 10537 T3486 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 10537 T3486 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty2/index forceNew:false
[junit4:junit4] 2> 10540 T3486 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4b7db8cd lockFactory=org.apache.lucene.store.NativeFSLockFactory@4daac53; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 10540 T3486 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 10541 T3486 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty2/index
[junit4:junit4] 2> 10542 T3486 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 10543 T3486 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 10543 T3486 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 10544 T3486 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 10544 T3486 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 10544 T3486 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 10545 T3486 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 10545 T3486 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 10545 T3486 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 10552 T3486 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 10558 T3486 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty2
[junit4:junit4] 2> 10558 T3486 oass.SolrIndexSearcher.<init> Opening Searcher@2792a97b main
[junit4:junit4] 2> 10559 T3486 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty2/tlog
[junit4:junit4] 2> 10559 T3486 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 10560 T3486 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 10564 T3487 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2792a97b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 10565 T3486 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 10566 T3486 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 11483 T3452 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 11484 T3452 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"2",
[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:27717_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:27717"}
[junit4:junit4] 2> 11484 T3452 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 11484 T3452 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 11532 T3451 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> 11532 T3485 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> 11532 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> 11532 T3470 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> 11568 T3486 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 11568 T3486 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:27717 collection:collection1 shard:shard2
[junit4:junit4] 2> 11568 T3486 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 11583 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0008 type:delete cxid:0x45 zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard2 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard2
[junit4:junit4] 2> 11584 T3486 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 11585 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0008 type:create cxid:0x46 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 11596 T3486 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 11596 T3486 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 11596 T3486 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:27717/collection1/
[junit4:junit4] 2> 11596 T3486 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 11597 T3486 oasc.SyncStrategy.syncToMe http://127.0.0.1:27717/collection1/ has no replicas
[junit4:junit4] 2> 11597 T3486 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:27717/collection1/
[junit4:junit4] 2> 11597 T3486 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 11600 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0008 type:create cxid:0x4f zxid:0x82 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13037 T3452 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13073 T3470 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> 13073 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> 13073 T3451 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> 13073 T3485 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> 13090 T3486 oasc.ZkController.register We are http://127.0.0.1:27717/collection1/ and leader is http://127.0.0.1:27717/collection1/
[junit4:junit4] 2> 13090 T3486 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:27717
[junit4:junit4] 2> 13090 T3486 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 13090 T3486 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 13090 T3486 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 13092 T3486 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13093 T3429 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1
[junit4:junit4] 2> 13093 T3429 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 13094 T3429 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 13277 T3429 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 13280 T3429 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:27720
[junit4:junit4] 2> 13281 T3429 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 13281 T3429 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 13282 T3429 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362173492586
[junit4:junit4] 2> 13282 T3429 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362173492586/solr.xml
[junit4:junit4] 2> 13283 T3429 oasc.CoreContainer.<init> New CoreContainer 1121607808
[junit4:junit4] 2> 13283 T3429 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362173492586/'
[junit4:junit4] 2> 13284 T3429 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362173492586/'
[junit4:junit4] 2> 13329 T3429 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 13329 T3429 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 13330 T3429 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 13330 T3429 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 13331 T3429 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 13331 T3429 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 13331 T3429 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 13332 T3429 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 13332 T3429 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 13333 T3429 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 13352 T3429 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 13370 T3429 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:27707/solr
[junit4:junit4] 2> 13370 T3429 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 13371 T3429 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:27707 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1d3d0872
[junit4:junit4] 2> 13372 T3429 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 13372 T3497 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:27707. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 13373 T3497 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:27707, initiating session
[junit4:junit4] 2> 13373 T3431 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:27721
[junit4:junit4] 2> 13373 T3431 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:27721
[junit4:junit4] 2> 13375 T3433 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d27ddca3f0009 with negotiated timeout 20000 for client /140.211.11.196:27721
[junit4:junit4] 2> 13375 T3497 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:27707, sessionid = 0x13d27ddca3f0009, negotiated timeout = 20000
[junit4:junit4] 2> 13376 T3498 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d3d0872 name:ZooKeeperConnection Watcher:127.0.0.1:27707 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 13376 T3429 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 13377 T3434 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d27ddca3f0009
[junit4:junit4] 2> 13390 T3498 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 13390 T3431 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:27721 which had sessionid 0x13d27ddca3f0009
[junit4:junit4] 2> 13390 T3429 oaz.ZooKeeper.close Session: 0x13d27ddca3f0009 closed
[junit4:junit4] 2> 13391 T3429 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 13405 T3429 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:27707/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@19ab6947
[junit4:junit4] 2> 13406 T3429 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 13406 T3499 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:27707. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 13407 T3499 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:27707, initiating session
[junit4:junit4] 2> 13407 T3431 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:27722
[junit4:junit4] 2> 13407 T3431 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:27722
[junit4:junit4] 2> 13409 T3433 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d27ddca3f000a with negotiated timeout 20000 for client /140.211.11.196:27722
[junit4:junit4] 2> 13409 T3499 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:27707, sessionid = 0x13d27ddca3f000a, negotiated timeout = 20000
[junit4:junit4] 2> 13409 T3500 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19ab6947 name:ZooKeeperConnection Watcher:127.0.0.1:27707/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 13409 T3429 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 13410 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f000a type:create cxid:0x1 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13411 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f000a type:create cxid:0x2 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13419 T3429 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 14421 T3429 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:27720_
[junit4:junit4] 2> 14422 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f000a type:delete cxid:0x9 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:27720_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:27720_
[junit4:junit4] 2> 14428 T3429 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:27720_
[junit4:junit4] 2> 14430 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> 14430 T3451 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> 14431 T3485 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14431 T3470 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14431 T3500 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14431 T3485 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> 14431 T3470 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> 14432 T3457 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14432 T3451 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14448 T3501 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362173492586/collection1
[junit4:junit4] 2> 14449 T3501 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 14449 T3501 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 14449 T3501 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 14450 T3501 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362173492586/collection1/'
[junit4:junit4] 2> 14452 T3501 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362173492586/collection1/lib/README' to classloader
[junit4:junit4] 2> 14452 T3501 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362173492586/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 14496 T3501 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 14553 T3501 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 14587 T3452 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 14588 T3452 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[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:27717_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:27717"}
[junit4:junit4] 2> 14601 T3485 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> 14601 T3451 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> 14601 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> 14601 T3470 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> 14653 T3501 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 14653 T3500 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> 14663 T3501 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 15246 T3501 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 15257 T3501 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 15261 T3501 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 15273 T3501 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 15278 T3501 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 15284 T3501 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 15324 T3501 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 15324 T3501 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 15324 T3501 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 15325 T3501 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 15326 T3501 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 15326 T3501 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1362173492586/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3/
[junit4:junit4] 2> 15326 T3501 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1414627a
[junit4:junit4] 2> 15327 T3501 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 15328 T3501 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3 forceNew:false
[junit4:junit4] 2> 15329 T3501 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3
[junit4:junit4] 2> 15329 T3501 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3/index/
[junit4:junit4] 2> 15330 T3501 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 15331 T3501 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3/index forceNew:false
[junit4:junit4] 2> 15358 T3501 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@7301adfb lockFactory=org.apache.lucene.store.NativeFSLockFactory@7a4bd52; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 15359 T3501 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 15360 T3501 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3/index
[junit4:junit4] 2> 15362 T3501 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 15362 T3501 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 15363 T3501 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 15364 T3501 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 15365 T3501 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 15365 T3501 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 15365 T3501 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 15366 T3501 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 15367 T3501 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 15377 T3501 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 15385 T3501 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3
[junit4:junit4] 2> 15385 T3501 oass.SolrIndexSearcher.<init> Opening Searcher@313ee49f main
[junit4:junit4] 2> 15386 T3501 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3/tlog
[junit4:junit4] 2> 15387 T3501 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 15387 T3501 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 15392 T3502 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@313ee49f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 15394 T3501 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 15394 T3501 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 16105 T3452 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 16106 T3452 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "numShards":"2",
[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:27720_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:27720"}
[junit4:junit4] 2> 16106 T3452 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 16106 T3452 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 16124 T3500 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> 16124 T3485 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> 16124 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> 16124 T3470 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> 16124 T3451 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> 16398 T3501 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 16398 T3501 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:27720 collection:collection1 shard:shard1
[junit4:junit4] 2> 16401 T3501 oasc.ZkController.register We are http://127.0.0.1:27720/collection1/ and leader is http://127.0.0.1:27714/collection1/
[junit4:junit4] 2> 16401 T3501 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:27720
[junit4:junit4] 2> 16401 T3501 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 16401 T3501 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C226 name=collection1 org.apache.solr.core.SolrCore@6122b55d url=http://127.0.0.1:27720/collection1 node=127.0.0.1:27720_ C226_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:27720_, base_url=http://127.0.0.1:27720}
[junit4:junit4] 2> 16402 T3503 C226 P27720 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 16402 T3503 C226 P27720 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 16402 T3503 C226 P27720 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 16402 T3503 C226 P27720 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 16403 T3501 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 16404 T3503 C226 P27720 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 16404 T3429 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1
[junit4:junit4] 2> 16405 T3429 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 16405 T3429 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 16424 T3429 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 16425 T3429 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 16436 T3461 oasc.CoreContainer.create Creating SolrCore 'onenodecollectioncore' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362173483332/onenodecollectioncore
[junit4:junit4] 2> 16437 T3461 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4] 2> 16437 T3461 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4] 2> 16438 T3461 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 16439 T3461 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 16439 T3461 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4] 2> 16442 T3461 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4] 2> 16443 T3461 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362173483332/onenodecollectioncore/'
[junit4:junit4] 2> 16502 T3461 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 16556 T3461 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 16657 T3461 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 16667 T3461 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 17253 T3461 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 17263 T3461 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 17268 T3461 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 17281 T3461 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 17288 T3461 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 17295 T3461 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 17296 T3461 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 17297 T3461 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 17297 T3461 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 17299 T3461 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 17299 T3461 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 17300 T3461 oasc.SolrCore.<init> [onenodecollectioncore] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1362173483332/onenodecollectioncore/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362173479482/onenodecollection/
[junit4:junit4] 2> 17301 T3461 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1414627a
[junit4:junit4] 2> 17301 T3461 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 17303 T3461 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362173479482/onenodecollection forceNew:false
[junit4:junit4] 2> 17303 T3461 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362173479482/onenodecollection
[junit4:junit4] 2> 17304 T3461 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362173479482/onenodecollection/index/
[junit4:junit4] 2> 17305 T3461 oasc.SolrCore.initIndex WARNING [onenodecollectioncore] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362173479482/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 17306 T3461 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362173479482/onenodecollection/index forceNew:false
[junit4:junit4] 2> 17310 T3461 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@61072154 lockFactory=org.apache.lucene.store.NativeFSLockFactory@59fe030; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 17310 T3461 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 17312 T3461 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362173479482/onenodecollection/index
[junit4:junit4] 2> 17314 T3461 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 17315 T3461 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 17316 T3461 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 17317 T3461 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 17317 T3461 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 17318 T3461 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 17319 T3461 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 17319 T3461 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 17320 T3461 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 17330 T3461 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 17338 T3461 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362173479482/onenodecollection
[junit4:junit4] 2> 17339 T3461 oass.SolrIndexSearcher.<init> Opening Searcher@3d0e7bf5 main
[junit4:junit4] 2> 17340 T3461 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362173479482/onenodecollection/tlog
[junit4:junit4] 2> 17341 T3461 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 17342 T3461 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 17346 T3504 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@3d0e7bf5 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 17349 T3461 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4] 2> 17629 T3452 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 17630 T3452 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "numShards":"2",
[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:27720_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:27720"}
[junit4:junit4] 2> 17634 T3452 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"onenodecollectioncore",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "node_name":"127.0.0.1:27714_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:27714"}
[junit4:junit4] 2> 17634 T3452 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4] 2> 17634 T3452 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 17651 T3485 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> 17651 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> 17651 T3470 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> 17651 T3500 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> 17651 T3451 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> 18355 T3461 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4] 2> 18355 T3461 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:27714 collection:onenodecollection shard:shard1
[junit4:junit4] 2> 18356 T3461 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4] 2> 18374 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0006 type:delete cxid:0x9f zxid:0xac txntype:-1 reqpath:n/a Error Path:/solr/collections/onenodecollection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/onenodecollection/leaders
[junit4:junit4] 2> 18380 T3461 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 18381 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0006 type:create cxid:0xa0 zxid:0xad txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 18383 T3461 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 18384 T3461 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 18384 T3461 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:27714/onenodecollectioncore/
[junit4:junit4] 2> 18384 T3461 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 18385 T3461 oasc.SyncStrategy.syncToMe http://127.0.0.1:27714/onenodecollectioncore/ has no replicas
[junit4:junit4] 2> 18385 T3461 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:27714/onenodecollectioncore/
[junit4:junit4] 2> 18385 T3461 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4] 2> 18390 T3434 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d27ddca3f0006 type:create cxid:0xaa zxid:0xb1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 19163 T3452 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 19205 T3451 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> 19205 T3500 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> 19205 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> 19205 T3470 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> 19205 T3485 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> 19215 T3461 oasc.ZkController.register We are http://127.0.0.1:27714/onenodecollectioncore/ and leader is http://127.0.0.1:27714/onenodecollectioncore/
[junit4:junit4] 2> 19215 T3461 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:27714
[junit4:junit4] 2> 19215 T3461 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 19216 T3461 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4] 2> 19217 T3461 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 19218 T3429 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4] 2> 19219 T3429 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 20221 T3429 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> C226_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:27720_, base_url=http://127.0.0.1:27720}
[junit4:junit4] 2> 20428 T3503 C226 P27720 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:27714/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 20428 T3503 C226 P27720 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:27720 START replicas=[http://127.0.0.1:27714/collection1/] nUpdates=100
[junit4:junit4] 2> 20428 T3503 C226 P27720 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 20429 T3503 C226 P27720 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 20429 T3503 C226 P27720 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 20429 T3503 C226 P27720 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 20429 T3503 C226 P27720 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 20429 T3503 C226 P27720 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:27714/collection1/. core=collection1
[junit4:junit4] 2> 20430 T3503 C226 P27720 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C227 name=collection1 org.apache.solr.core.SolrCore@15acc251 url=http://127.0.0.1:27714/collection1 node=127.0.0.1:27714_ C227_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:27714_, base_url=http://127.0.0.1:27714, leader=true}
[junit4:junit4] 2> 20435 T3462 C227 P27714 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 20444 T3463 C227 P27714 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 20445 T3463 C227 P27714 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty1
[junit4:junit4] 2> 20447 T3463 C227 P27714 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@41afc692 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b7ffabb; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 20448 T3463 C227 P27714 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 20448 T3463 C227 P27714 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@41afc692 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b7ffabb; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@41afc692 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b7ffabb; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 20449 T3463 C227 P27714 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 20449 T3463 C227 P27714 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty1
[junit4:junit4] 2> 20450 T3463 C227 P27714 oass.SolrIndexSearcher.<init> Opening Searcher@12e25589 realtime
[junit4:junit4] 2> 20450 T3463 C227 P27714 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 20450 T3463 C227 P27714 /update {waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 6
[junit4:junit4] 2> 20451 T3503 C226 P27720 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 20451 T3503 C226 P27720 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 20453 T3464 C227 P27714 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 20453 T3464 C227 P27714 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 20453 T3503 C226 P27720 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 20454 T3503 C226 P27720 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 20454 T3503 C226 P27720 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 20456 T3464 C227 P27714 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty1
[junit4:junit4] 2> 20456 T3464 C227 P27714 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty1/index
[junit4:junit4] 2> 20457 T3464 C227 P27714 REQ /replication {command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1
[junit4:junit4] 2> 20457 T3503 C226 P27720 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 20458 T3503 C226 P27720 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3/index.20130301183139936 forceNew:false
[junit4:junit4] 2> 20458 T3503 C226 P27720 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3
[junit4:junit4] 2> 20459 T3503 C226 P27720 oash.SnapPuller.fetchLatestIndex Starting download to BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2f5cf1ba lockFactory=org.apache.lucene.store.NativeFSLockFactory@5cfa9784) fullCopy=false
[junit4:junit4] 2> 20461 T3464 C227 P27714 REQ /replication {file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 20462 T3503 C226 P27720 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3/index
[junit4:junit4] 2> 20462 T3503 C226 P27720 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 20463 T3503 C226 P27720 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3
[junit4:junit4] 2> 20463 T3503 C226 P27720 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3
[junit4:junit4] 2> 20463 T3503 C226 P27720 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 20463 T3503 C226 P27720 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 20464 T3503 C226 P27720 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3
[junit4:junit4] 2> 20465 T3503 C226 P27720 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@7301adfb lockFactory=org.apache.lucene.store.NativeFSLockFactory@7a4bd52; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@7301adfb lockFactory=org.apache.lucene.store.NativeFSLockFactory@7a4bd52; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 20465 T3503 C226 P27720 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 20466 T3503 C226 P27720 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 20466 T3503 C226 P27720 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3
[junit4:junit4] 2> 20466 T3503 C226 P27720 oass.SolrIndexSearcher.<init> Opening Searcher@36f2b38a main
[junit4:junit4] 2> 20467 T3502 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@36f2b38a main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 20467 T3502 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3/index
[junit4:junit4] 2> 20468 T3503 C226 P27720 oash.SnapPuller.fetchLatestIndex removing temporary index download directory files BaseDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2f5cf1ba lockFactory=org.apache.lucene.store.NativeFSLockFactory@5cfa9784)
[junit4:junit4] 2> 20468 T3503 C226 P27720 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3/index.20130301183139936
[junit4:junit4] 2> 20468 T3503 C226 P27720 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3/index
[junit4:junit4] 2> 20468 T3503 C226 P27720 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 20469 T3503 C226 P27720 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 20469 T3503 C226 P27720 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 20469 T3503 C226 P27720 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 20477 T3503 C226 P27720 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 20711 T3452 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 20712 T3452 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":"none",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"onenodecollectioncore",
[junit4:junit4] 2> "collection":"onenodecollection",
[junit4:junit4] 2> "node_name":"127.0.0.1:27714_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:27714"}
[junit4:junit4] 2> 20725 T3452 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "numShards":"2",
[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:27720_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:27720"}
[junit4:junit4] 2> 20729 T3485 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> 20729 T3451 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> 20729 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> 20729 T3500 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> 20729 T3470 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> 21223 T3429 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 21224 T3429 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4] 2> 21224 T3429 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C228 name=onenodecollectioncore org.apache.solr.core.SolrCore@77080b7f url=http://127.0.0.1:27714/onenodecollectioncore node=127.0.0.1:27714_ C228_STATE=coll:onenodecollection core:onenodecollectioncore props:{shard=shard1, roles=none, state=active, core=onenodecollectioncore, collection=onenodecollection, node_name=127.0.0.1:27714_, base_url=http://127.0.0.1:27714, leader=true}
[junit4:junit4] 2> 21250 T3465 C228 P27714 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362173479482/onenodecollection
[junit4:junit4] 2> 21252 T3465 C228 P27714 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@61072154 lockFactory=org.apache.lucene.store.NativeFSLockFactory@59fe030; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 21252 T3465 C228 P27714 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 21254 T3465 C228 P27714 /update {wt=javabin&version=2} {add=[1 (1428342440699363328)]} 0 4
[junit4:junit4] 2> 21261 T3465 C228 P27714 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 21265 T3465 C228 P27714 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@61072154 lockFactory=org.apache.lucene.store.NativeFSLockFactory@59fe030; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@61072154 lockFactory=org.apache.lucene.store.NativeFSLockFactory@59fe030; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_2,generation=2,filenames=[_0_Asserting_0.tim, _0_Asserting_0.tip, _0_TestBloomFilteredLucene41Postings_0.tim, _0_MockVariableIntBlock_0.doc, _0_TestBloomFilteredLucene41Postings_0.tip, _0_MockVariableIntBlock_0.skp, _0_NestedPulsing_0.tip, _0_TestBloomFilteredLucene41Postings_0.pos, _0_NestedPulsing_0.tim, _0_NestedPulsing_0.pos, _0_MockVariableIntBlock_0.pyl, _0_MockVariableIntBlock_0.tib, _0.nvd, _0_MockVariableIntBlock_0.pos, _0.si, _0_Asserting_0.doc, _0_MockVariableIntBlock_0.tii, _0_NestedPulsing_0.doc, _0.fnm, _0_Disk_0.dvdd, _0_TestBloomFilteredLucene41Postings_0.blm, _0.nvm, _0_Disk_0.dvdm, _0_MockVariableIntBlock_0.frq, _0_TestBloomFilteredLucene41Postings_0.doc, segments_2, _0.fdx, _0_Asserting_0.pos, _0.fdt]
[junit4:junit4] 2> 21265 T3465 C228 P27714 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_0_Asserting_0.tim, _0_Asserting_0.tip, _0_TestBloomFilteredLucene41Postings_0.tim, _0_MockVariableIntBlock_0.doc, _0_TestBloomFilteredLucene41Postings_0.tip, _0_MockVariableIntBlock_0.skp, _0_NestedPulsing_0.tip, _0_TestBloomFilteredLucene41Postings_0.pos, _0_NestedPulsing_0.tim, _0_NestedPulsing_0.pos, _0_MockVariableIntBlock_0.pyl, _0_MockVariableIntBlock_0.tib, _0.nvd, _0_MockVariableIntBlock_0.pos, _0.si, _0_Asserting_0.doc, _0_MockVariableIntBlock_0.tii, _0_NestedPulsing_0.doc, _0.fnm, _0_Disk_0.dvdd, _0_TestBloomFilteredLucene41Postings_0.blm, _0.nvm, _0_Disk_0.dvdm, _0_MockVariableIntBlock_0.frq, _0_TestBloomFilteredLucene41Postings_0.doc, segments_2, _0.fdx, _0_Asserting_0.pos, _0.fdt]
[junit4:junit4] 2> 21266 T3465 C228 P27714 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362173479482/onenodecollection
[junit4:junit4] 2> 21268 T3465 C228 P27714 oass.SolrIndexSearcher.<init> Opening Searcher@2b16dd90 main
[junit4:junit4] 2> 21268 T3465 C228 P27714 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 21269 T3504 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@2b16dd90 main{StandardDirectoryReader(segments_2:3 _0(5.0):C1)}
[junit4:junit4] 2> 21269 T3504 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1362173479482/onenodecollection/index
[junit4:junit4] 2> 21270 T3465 C228 P27714 /update {waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 9
[junit4:junit4] 2> 21274 T3465 C228 P27714 REQ /select {q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=1
[junit4:junit4] 2> 21275 T3429 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 21288 T3465 C228 P27714 REQ /select {q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=0
[junit4:junit4] 2> ASYNC NEW_CORE C229 name=collection1 org.apache.solr.core.SolrCore@67d79fa7 url=http://127.0.0.1:27710/collection1 node=127.0.0.1:27710_ C229_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:27710_, base_url=http://127.0.0.1:27710, leader=true}
[junit4:junit4] 2> 21296 T3441 C229 P27710 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/control/data
[junit4:junit4] 2> 21298 T3441 C229 P27710 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@e9560a lockFactory=org.apache.lucene.store.NativeFSLockFactory@2fcd9aaa; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 21298 T3441 C229 P27710 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 21301 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[1 (1428342440747597824)]} 0 6
[junit4:junit4] 2> C226_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:27720_, base_url=http://127.0.0.1:27720}
[junit4:junit4] 2> 21326 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1428342440767520768)]} 0 2
[junit4:junit4] 2> 21327 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[1 (1428342440767520768)]} 0 13
[junit4:junit4] 2> 21330 T3441 C229 P27710 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 21335 T3441 C229 P27710 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@e9560a lockFactory=org.apache.lucene.store.NativeFSLockFactory@2fcd9aaa; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@e9560a lockFactory=org.apache.lucene.store.NativeFSLockFactory@2fcd9aaa; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_2,generation=2,filenames=[_0_Asserting_0.tim, _0_Asserting_0.tip, _0_MockVariableIntBlock_0.doc, _0_TestBloomFilteredLucene41Postings_0.tim, _0_MockVariableIntBlock_0.skp, _0_TestBloomFilteredLucene41Postings_0.tip, _0_NestedPulsing_0.tip, _0_TestBloomFilteredLucene41Postings_0.pos, _0_NestedPulsing_0.tim, _0_MockVariableIntBlock_0.pyl, _0_NestedPulsing_0.pos, _0_MockVariableIntBlock_0.tib, _0.nvd, _0_MockVariableIntBlock_0.pos, _0.si, _0_Asserting_0.doc, _0_MockVariableIntBlock_0.tii, _0_NestedPulsing_0.doc, _0.fnm, _0_Disk_0.dvdd, _0_TestBloomFilteredLucene41Postings_0.blm, _0.nvm, _0_Disk_0.dvdm, _0_MockVariableIntBlock_0.frq, _0_TestBloomFilteredLucene41Postings_0.doc, segments_2, _0.fdx, _0_Asserting_0.pos, _0.fdt]
[junit4:junit4] 2> 21335 T3441 C229 P27710 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_0_Asserting_0.tim, _0_Asserting_0.tip, _0_MockVariableIntBlock_0.doc, _0_TestBloomFilteredLucene41Postings_0.tim, _0_MockVariableIntBlock_0.skp, _0_TestBloomFilteredLucene41Postings_0.tip, _0_NestedPulsing_0.tip, _0_TestBloomFilteredLucene41Postings_0.pos, _0_NestedPulsing_0.tim, _0_MockVariableIntBlock_0.pyl, _0_NestedPulsing_0.pos, _0_MockVariableIntBlock_0.tib, _0.nvd, _0_MockVariableIntBlock_0.pos, _0.si, _0_Asserting_0.doc, _0_MockVariableIntBlock_0.tii, _0_NestedPulsing_0.doc, _0.fnm, _0_Disk_0.dvdd, _0_TestBloomFilteredLucene41Postings_0.blm, _0.nvm, _0_Disk_0.dvdm, _0_MockVariableIntBlock_0.frq, _0_TestBloomFilteredLucene41Postings_0.doc, segments_2, _0.fdx, _0_Asserting_0.pos, _0.fdt]
[junit4:junit4] 2> 21336 T3441 C229 P27710 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/control/data
[junit4:junit4] 2> 21338 T3441 C229 P27710 oass.SolrIndexSearcher.<init> Opening Searcher@31fdb3b4 main
[junit4:junit4] 2> 21338 T3441 C229 P27710 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 21339 T3455 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@31fdb3b4 main{StandardDirectoryReader(segments_2:3 _0(5.0):C1)}
[junit4:junit4] 2> 21339 T3455 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/control/data/index
[junit4:junit4] 2> 21340 T3441 C229 P27710 /update {waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 10
[junit4:junit4] 2> 21342 T3466 C227 P27714 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 21347 T3466 C227 P27714 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@41afc692 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b7ffabb; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@41afc692 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b7ffabb; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_3,generation=3,filenames=[_0_Asserting_0.tim, _0_Asserting_0.tip, _0_MockVariableIntBlock_0.doc, _0_TestBloomFilteredLucene41Postings_0.tim, _0_MockVariableIntBlock_0.skp, _0_TestBloomFilteredLucene41Postings_0.tip, _0_NestedPulsing_0.tip, _0_TestBloomFilteredLucene41Postings_0.pos, _0_NestedPulsing_0.tim, _0_MockVariableIntBlock_0.pyl, _0_NestedPulsing_0.pos, _0_MockVariableIntBlock_0.tib, _0.nvd, _0_MockVariableIntBlock_0.pos, _0.si, _0_Asserting_0.doc, _0_MockVariableIntBlock_0.tii, _0_NestedPulsing_0.doc, _0.fnm, _0_Disk_0.dvdd, _0_TestBloomFilteredLucene41Postings_0.blm, _0.nvm, _0_Disk_0.dvdm, _0_MockVariableIntBlock_0.frq, _0_TestBloomFilteredLucene41Postings_0.doc, _0.fdx, _0_Asserting_0.pos, _0.fdt, segments_3]
[junit4:junit4] 2> 21348 T3466 C227 P27714 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0_Asserting_0.tim, _0_Asserting_0.tip, _0_MockVariableIntBlock_0.doc, _0_TestBloomFilteredLucene41Postings_0.tim, _0_MockVariableIntBlock_0.skp, _0_TestBloomFilteredLucene41Postings_0.tip, _0_NestedPulsing_0.tip, _0_TestBloomFilteredLucene41Postings_0.pos, _0_NestedPulsing_0.tim, _0_MockVariableIntBlock_0.pyl, _0_NestedPulsing_0.pos, _0_MockVariableIntBlock_0.tib, _0.nvd, _0_MockVariableIntBlock_0.pos, _0.si, _0_Asserting_0.doc, _0_MockVariableIntBlock_0.tii, _0_NestedPulsing_0.doc, _0.fnm, _0_Disk_0.dvdd, _0_TestBloomFilteredLucene41Postings_0.blm, _0.nvm, _0_Disk_0.dvdm, _0_MockVariableIntBlock_0.frq, _0_TestBloomFilteredLucene41Postings_0.doc, _0.fdx, _0_Asserting_0.pos, _0.fdt, segments_3]
[junit4:junit4] 2> 21348 T3466 C227 P27714 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty1
[junit4:junit4] 2> 21350 T3466 C227 P27714 oass.SolrIndexSearcher.<init> Opening Searcher@1861be9e main
[junit4:junit4] 2> 21350 T3466 C227 P27714 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty1/index
[junit4:junit4] 2> 21351 T3466 C227 P27714 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 21351 T3472 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1861be9e main{StandardDirectoryReader(segments_3:3:nrt _0(5.0):C1)}
[junit4:junit4] 2> 21352 T3472 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty1/index
[junit4:junit4] 2> 21352 T3466 C227 P27714 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:27720/collection1/, StdNode: http://127.0.0.1:27717/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4] 2> 21354 T3490 C226 P27720 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 21359 T3490 C226 P27720 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@7301adfb lockFactory=org.apache.lucene.store.NativeFSLockFactory@7a4bd52; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@7301adfb lockFactory=org.apache.lucene.store.NativeFSLockFactory@7a4bd52; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_3,generation=3,filenames=[_0_Asserting_0.tim, _0_Asserting_0.tip, _0_MockVariableIntBlock_0.doc, _0_TestBloomFilteredLucene41Postings_0.tim, _0_MockVariableIntBlock_0.skp, _0_TestBloomFilteredLucene41Postings_0.tip, _0_NestedPulsing_0.tip, _0_TestBloomFilteredLucene41Postings_0.pos, _0_NestedPulsing_0.tim, _0_MockVariableIntBlock_0.pyl, _0_NestedPulsing_0.pos, _0_MockVariableIntBlock_0.tib, _0.nvd, _0_MockVariableIntBlock_0.pos, _0.si, _0_Asserting_0.doc, _0_MockVariableIntBlock_0.tii, _0_NestedPulsing_0.doc, _0.fnm, _0_Disk_0.dvdd, _0_TestBloomFilteredLucene41Postings_0.blm, _0.nvm, _0_Disk_0.dvdm, _0_MockVariableIntBlock_0.frq, _0_TestBloomFilteredLucene41Postings_0.doc, _0.fdx, _0_Asserting_0.pos, _0.fdt, segments_3]
[junit4:junit4] 2> ASYNC NEW_CORE C230 name=collection1 org.apache.solr.core.SolrCore@1be4fb52 url=http://127.0.0.1:27717/collection1 node=127.0.0.1:27717_ C230_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:27717_, base_url=http://127.0.0.1:27717, leader=true}
[junit4:junit4] 2> 21359 T3477 C230 P27717 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 21360 T3490 C226 P27720 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0_Asserting_0.tim, _0_Asserting_0.tip, _0_MockVariableIntBlock_0.doc, _0_TestBloomFilteredLucene41Postings_0.tim, _0_MockVariableIntBlock_0.skp, _0_TestBloomFilteredLucene41Postings_0.tip, _0_NestedPulsing_0.tip, _0_TestBloomFilteredLucene41Postings_0.pos, _0_NestedPulsing_0.tim, _0_MockVariableIntBlock_0.pyl, _0_NestedPulsing_0.pos, _0_MockVariableIntBlock_0.tib, _0.nvd, _0_MockVariableIntBlock_0.pos, _0.si, _0_Asserting_0.doc, _0_MockVariableIntBlock_0.tii, _0_NestedPulsing_0.doc, _0.fnm, _0_Disk_0.dvdd, _0_TestBloomFilteredLucene41Postings_0.blm, _0.nvm, _0_Disk_0.dvdm, _0_MockVariableIntBlock_0.frq, _0_TestBloomFilteredLucene41Postings_0.doc, _0.fdx, _0_Asserting_0.pos, _0.fdt, segments_3]
[junit4:junit4] 2> 21360 T3477 C230 P27717 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty2
[junit4:junit4] 2> 21360 T3490 C226 P27720 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3
[junit4:junit4] 2> 21362 T3477 C230 P27717 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4b7db8cd lockFactory=org.apache.lucene.store.NativeFSLockFactory@4daac53; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 21363 T3477 C230 P27717 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 21363 T3477 C230 P27717 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4b7db8cd lockFactory=org.apache.lucene.store.NativeFSLockFactory@4daac53; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4b7db8cd lockFactory=org.apache.lucene.store.NativeFSLockFactory@4daac53; maxCacheMB=0.6826171875 maxMergeSizeMB=0.8603515625)),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 21364 T3477 C230 P27717 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 21364 T3477 C230 P27717 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty2
[junit4:junit4] 2> 21365 T3477 C230 P27717 oass.SolrIndexSearcher.<init> Opening Searcher@64668b74 main
[junit4:junit4] 2> 21365 T3477 C230 P27717 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 21366 T3487 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@64668b74 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 21366 T3487 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty2/index
[junit4:junit4] 2> 21366 T3477 C230 P27717 /update {waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 7
[junit4:junit4] 2> 21412 T3490 C226 P27720 oass.SolrIndexSearcher.<init> Opening Searcher@764f8d21 main
[junit4:junit4] 2> 21413 T3490 C226 P27720 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 21413 T3502 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@764f8d21 main{StandardDirectoryReader(segments_3:3:nrt _0(5.0):C1)}
[junit4:junit4] 2> 21414 T3502 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3/index
[junit4:junit4] 2> 21414 T3490 C226 P27720 /update {waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 60
[junit4:junit4] 2> 21415 T3466 C227 P27714 /update {waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 73
[junit4:junit4] 2> 21415 T3429 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):230
[junit4:junit4] 2> 21416 T3429 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 21417 T3429 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4] 2> 21420 T3441 C229 P27710 REQ /select {q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=0
[junit4:junit4] 2> 21421 T3429 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:27707/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@60baae35
[junit4:junit4] 2> 21422 T3429 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 21423 T3510 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:27707. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 21423 T3510 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:27707, initiating session
[junit4:junit4] 2> 21423 T3431 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:27751
[junit4:junit4] 2> 21424 T3431 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:27751
[junit4:junit4] 2> 21425 T3433 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d27ddca3f000b with negotiated timeout 10000 for client /140.211.11.196:27751
[junit4:junit4] 2> 21425 T3510 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:27707, sessionid = 0x13d27ddca3f000b, negotiated timeout = 10000
[junit4:junit4] 2> 21425 T3511 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@60baae35 name:ZooKeeperConnection Watcher:127.0.0.1:27707/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 21426 T3429 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 21427 T3429 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 21429 T3434 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d27ddca3f000b
[junit4:junit4] 2> 21430 T3511 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 21430 T3431 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:27751 which had sessionid 0x13d27ddca3f000b
[junit4:junit4] 2> 21430 T3429 oaz.ZooKeeper.close Session: 0x13d27ddca3f000b closed
[junit4:junit4] 2> 21432 T3460 C227 P27714 REQ /select {q=*:*&distrib=false&wt=javabin&version=2} hits=1 status=0 QTime=1
[junit4:junit4] 2> 21434 T3478 C230 P27717 REQ /select {q=*:*&distrib=false&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4:junit4] 2> 21438 T3480 C230 P27717 REQ /select {NOW=1362173500913&shard.url=127.0.0.1:27717/collection1/&fl=id,score&start=0&q=*:*&distrib=false&wt=javabin&isShard=true&fsv=true&version=2&rows=10} hits=0 status=0 QTime=0
[junit4:junit4] 2> 21438 T3491 C226 P27720 REQ /select {NOW=1362173500913&shard.url=127.0.0.1:27714/collection1/|127.0.0.1:27720/collection1/&fl=id,score&start=0&q=*:*&distrib=false&wt=javabin&isShard=true&fsv=true&version=2&rows=10} hits=1 status=0 QTime=0
[junit4:junit4] 2> 21442 T3491 C226 P27720 REQ /select {NOW=1362173500913&shard.url=127.0.0.1:27714/collection1/|127.0.0.1:27720/collection1/&ids=1&q=*:*&distrib=false&wt=javabin&isShard=true&version=2} status=0 QTime=0
[junit4:junit4] 2> 21443 T3479 C230 P27717 REQ /select {q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=8
[junit4:junit4] 2> 21448 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[2 (1428342440904884224)]} 0 2
[junit4:junit4] 2> 21453 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[2 (1428342440910127104)]} 0 2
[junit4:junit4] 2> 21457 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[3 (1428342440915369984)]} 0 1
[junit4:junit4] 2> 21460 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[3 (1428342440918515712)]} 0 1
[junit4:junit4] 2> 21463 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[4 (1428342440921661440)]} 0 1
[junit4:junit4] 2> 21471 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[4 (1428342440924807168)]} 0 2
[junit4:junit4] 2> 21471 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[4 (1428342440924807168)]} 0 6
[junit4:junit4] 2> 21475 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[5 (1428342440934244352)]} 0 1
[junit4:junit4] 2> 21478 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[5 (1428342440937390080)]} 0 1
[junit4:junit4] 2> 21481 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[6 (1428342440940535808)]} 0 1
[junit4:junit4] 2> 21486 T3477 C230 P27717 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[6 (1428342440945778688)]} 0 1
[junit4:junit4] 2> 21487 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[6]} 0 4
[junit4:junit4] 2> 21490 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[7 (1428342440949972992)]} 0 1
[junit4:junit4] 2> 21495 T3477 C230 P27717 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[7 (1428342440955215872)]} 0 1
[junit4:junit4] 2> 21495 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[7]} 0 3
[junit4:junit4] 2> 21499 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[8 (1428342440959410176)]} 0 1
[junit4:junit4] 2> 21507 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[8 (1428342440964653056)]} 0 1
[junit4:junit4] 2> 21507 T3463 C227 P27714 /update {distrib.from=http://127.0.0.1:27717/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[8 (1428342440964653056)]} 0 4
[junit4:junit4] 2> 21508 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[8]} 0 7
[junit4:junit4] 2> 21512 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[9 (1428342440973041664)]} 0 1
[junit4:junit4] 2> 21515 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[9 (1428342440976187392)]} 0 1
[junit4:junit4] 2> 21518 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[10 (1428342440979333120)]} 0 1
[junit4:junit4] 2> 21526 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10 (1428342440984576000)]} 0 1
[junit4:junit4] 2> 21526 T3463 C227 P27714 /update {distrib.from=http://127.0.0.1:27717/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[10 (1428342440984576000)]} 0 4
[junit4:junit4] 2> 21527 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[10]} 0 7
[junit4:junit4] 2> 21530 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[11 (1428342440991916032)]} 0 1
[junit4:junit4] 2> 21536 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[11 (1428342440995061760)]} 0 1
[junit4:junit4] 2> 21536 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[11 (1428342440995061760)]} 0 4
[junit4:junit4] 2> 21540 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[12 (1428342441002401792)]} 0 1
[junit4:junit4] 2> 21548 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[12 (1428342441007644672)]} 0 1
[junit4:junit4] 2> 21548 T3463 C227 P27714 /update {distrib.from=http://127.0.0.1:27717/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[12 (1428342441007644672)]} 0 4
[junit4:junit4] 2> 21549 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[12]} 0 7
[junit4:junit4] 2> 21553 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[13 (1428342441016033280)]} 0 1
[junit4:junit4] 2> 21561 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[13 (1428342441021276160)]} 0 1
[junit4:junit4] 2> 21561 T3463 C227 P27714 /update {distrib.from=http://127.0.0.1:27717/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[13 (1428342441021276160)]} 0 4
[junit4:junit4] 2> 21562 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[13]} 0 7
[junit4:junit4] 2> 21566 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[14 (1428342441029664768)]} 0 1
[junit4:junit4] 2> 21572 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[14 (1428342441032810496)]} 0 1
[junit4:junit4] 2> 21572 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[14 (1428342441032810496)]} 0 4
[junit4:junit4] 2> 21576 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[15 (1428342441040150528)]} 0 1
[junit4:junit4] 2> 21584 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[15 (1428342441045393408)]} 0 1
[junit4:junit4] 2> 21584 T3463 C227 P27714 /update {distrib.from=http://127.0.0.1:27717/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[15 (1428342441045393408)]} 0 4
[junit4:junit4] 2> 21585 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[15]} 0 7
[junit4:junit4] 2> 21589 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[16 (1428342441053782016)]} 0 1
[junit4:junit4] 2> 21595 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[16 (1428342441056927744)]} 0 1
[junit4:junit4] 2> 21595 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[16 (1428342441056927744)]} 0 4
[junit4:junit4] 2> 21600 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[17 (1428342441064267776)]} 0 2
[junit4:junit4] 2> 21605 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[17 (1428342441069510656)]} 0 3
[junit4:junit4] 2> 21608 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[100 (1428342441073704960)]} 0 1
[junit4:junit4] 2> 21614 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[100 (1428342441076850688)]} 0 1
[junit4:junit4] 2> 21614 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[100 (1428342441076850688)]} 0 4
[junit4:junit4] 2> 21618 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[101 (1428342441084190720)]} 0 1
[junit4:junit4] 2> 21626 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[101 (1428342441089433600)]} 0 1
[junit4:junit4] 2> 21626 T3463 C227 P27714 /update {distrib.from=http://127.0.0.1:27717/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[101 (1428342441089433600)]} 0 4
[junit4:junit4] 2> 21627 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[101]} 0 7
[junit4:junit4] 2> 21631 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[102 (1428342441097822208)]} 0 1
[junit4:junit4] 2> 21637 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[102 (1428342441100967936)]} 0 1
[junit4:junit4] 2> 21637 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[102 (1428342441100967936)]} 0 4
[junit4:junit4] 2> 21641 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[103 (1428342441108307968)]} 0 1
[junit4:junit4] 2> 21646 T3477 C230 P27717 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[103 (1428342441113550848)]} 0 1
[junit4:junit4] 2> 21646 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[103]} 0 3
[junit4:junit4] 2> 21650 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[104 (1428342441117745152)]} 0 1
[junit4:junit4] 2> 21653 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[104 (1428342441120890880)]} 0 1
[junit4:junit4] 2> 21655 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[105 (1428342441124036608)]} 0 0
[junit4:junit4] 2> 21661 T3477 C230 P27717 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[105 (1428342441129279488)]} 0 1
[junit4:junit4] 2> 21661 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[105]} 0 3
[junit4:junit4] 2> 21665 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[106 (1428342441133473792)]} 0 1
[junit4:junit4] 2> 21668 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[106 (1428342441136619520)]} 0 1
[junit4:junit4] 2> 21671 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[107 (1428342441139765248)]} 0 1
[junit4:junit4] 2> 21677 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[107 (1428342441142910976)]} 0 1
[junit4:junit4] 2> 21677 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[107 (1428342441142910976)]} 0 4
[junit4:junit4] 2> 21681 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[108 (1428342441150251008)]} 0 1
[junit4:junit4] 2> 21687 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[108 (1428342441153396736)]} 0 1
[junit4:junit4] 2> 21687 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[108 (1428342441153396736)]} 0 4
[junit4:junit4] 2> 21691 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[109 (1428342441160736768)]} 0 1
[junit4:junit4] 2> 21697 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[109 (1428342441163882496)]} 0 1
[junit4:junit4] 2> 21697 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[109 (1428342441163882496)]} 0 4
[junit4:junit4] 2> 21701 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[110 (1428342441171222528)]} 0 1
[junit4:junit4] 2> 21707 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[110 (1428342441174368256)]} 0 1
[junit4:junit4] 2> 21707 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[110 (1428342441174368256)]} 0 4
[junit4:junit4] 2> 21711 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[111 (1428342441181708288)]} 0 1
[junit4:junit4] 2> 21719 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[111 (1428342441186951168)]} 0 1
[junit4:junit4] 2> 21720 T3463 C227 P27714 /update {distrib.from=http://127.0.0.1:27717/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[111 (1428342441186951168)]} 0 5
[junit4:junit4] 2> 21720 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[111]} 0 7
[junit4:junit4] 2> 21724 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[112 (1428342441195339776)]} 0 1
[junit4:junit4] 2> 21729 T3477 C230 P27717 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[112 (1428342441200582656)]} 0 1
[junit4:junit4] 2> 21729 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[112]} 0 3
[junit4:junit4] 2> 21733 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[113 (1428342441204776960)]} 0 1
[junit4:junit4] 2> 21739 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[113 (1428342441207922688)]} 0 1
[junit4:junit4] 2> 21740 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[113 (1428342441207922688)]} 0 5
[junit4:junit4] 2> 21743 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[114 (1428342441215262720)]} 0 1
[junit4:junit4] 2> 21749 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[114 (1428342441218408448)]} 0 1
[junit4:junit4] 2> 21750 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[114 (1428342441218408448)]} 0 5
[junit4:junit4] 2> 21753 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[115 (1428342441225748480)]} 0 1
[junit4:junit4] 2> 21758 T3477 C230 P27717 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[115 (1428342441230991360)]} 0 1
[junit4:junit4] 2> 21758 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[115]} 0 3
[junit4:junit4] 2> 21762 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[116 (1428342441235185664)]} 0 1
[junit4:junit4] 2> 21767 T3477 C230 P27717 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[116 (1428342441240428544)]} 0 1
[junit4:junit4] 2> 21767 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[116]} 0 3
[junit4:junit4] 2> 21771 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[117 (1428342441244622848)]} 0 1
[junit4:junit4] 2> 21776 T3477 C230 P27717 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[117 (1428342441249865728)]} 0 1
[junit4:junit4] 2> 21776 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[117]} 0 3
[junit4:junit4] 2> 21780 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[118 (1428342441254060032)]} 0 1
[junit4:junit4] 2> 21788 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[118 (1428342441259302912)]} 0 1
[junit4:junit4] 2> 21788 T3463 C227 P27714 /update {distrib.from=http://127.0.0.1:27717/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[118 (1428342441259302912)]} 0 4
[junit4:junit4] 2> 21789 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[118]} 0 7
[junit4:junit4] 2> 21792 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[119 (1428342441266642944)]} 0 1
[junit4:junit4] 2> 21797 T3477 C230 P27717 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[119 (1428342441271885824)]} 0 1
[junit4:junit4] 2> 21797 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[119]} 0 3
[junit4:junit4] 2> 21801 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[120 (1428342441276080128)]} 0 1
[junit4:junit4] 2> 21806 T3477 C230 P27717 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[120 (1428342441281323008)]} 0 1
[junit4:junit4] 2> 21806 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[120]} 0 3
[junit4:junit4] 2> 21810 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[121 (1428342441285517312)]} 0 1
[junit4:junit4] 2> 21813 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[121 (1428342441288663040)]} 0 1
[junit4:junit4] 2> 21816 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[122 (1428342441291808768)]} 0 1
[junit4:junit4] 2> 21822 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[122 (1428342441294954496)]} 0 1
[junit4:junit4] 2> 21822 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[122 (1428342441294954496)]} 0 4
[junit4:junit4] 2> 21826 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[123 (1428342441302294528)]} 0 1
[junit4:junit4] 2> 21832 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[123 (1428342441305440256)]} 0 1
[junit4:junit4] 2> 21832 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[123 (1428342441305440256)]} 0 4
[junit4:junit4] 2> 21836 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[124 (1428342441312780288)]} 0 1
[junit4:junit4] 2> 21844 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[124 (1428342441318023168)]} 0 1
[junit4:junit4] 2> 21844 T3463 C227 P27714 /update {distrib.from=http://127.0.0.1:27717/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[124 (1428342441318023168)]} 0 4
[junit4:junit4] 2> 21845 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[124]} 0 7
[junit4:junit4] 2> 21847 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[125 (1428342441325363200)]} 0 0
[junit4:junit4] 2> 21854 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[125 (1428342441328508928)]} 0 1
[junit4:junit4] 2> 21854 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[125 (1428342441328508928)]} 0 4
[junit4:junit4] 2> 21858 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[126 (1428342441335848960)]} 0 1
[junit4:junit4] 2> 21864 T3477 C230 P27717 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[126 (1428342441342140416)]} 0 1
[junit4:junit4] 2> 21864 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[126]} 0 3
[junit4:junit4] 2> 21868 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[127 (1428342441346334720)]} 0 1
[junit4:junit4] 2> 21873 T3477 C230 P27717 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[127 (1428342441351577600)]} 0 1
[junit4:junit4] 2> 21873 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[127]} 0 3
[junit4:junit4] 2> 21877 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[128 (1428342441355771904)]} 0 1
[junit4:junit4] 2> 21883 T3477 C230 P27717 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[128 (1428342441362063360)]} 0 1
[junit4:junit4] 2> 21883 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[128]} 0 3
[junit4:junit4] 2> 21887 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[129 (1428342441366257664)]} 0 1
[junit4:junit4] 2> 21893 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[129 (1428342441369403392)]} 0 1
[junit4:junit4] 2> 21893 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[129 (1428342441369403392)]} 0 4
[junit4:junit4] 2> 21897 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[130 (1428342441376743424)]} 0 1
[junit4:junit4] 2> 21900 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[130 (1428342441379889152)]} 0 1
[junit4:junit4] 2> 21903 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[131 (1428342441383034880)]} 0 1
[junit4:junit4] 2> 21906 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[131 (1428342441386180608)]} 0 1
[junit4:junit4] 2> 21909 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[132 (1428342441389326336)]} 0 1
[junit4:junit4] 2> 21915 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[132 (1428342441392472064)]} 0 1
[junit4:junit4] 2> 21915 T3466 C227 P27714 /update {wt=javabin&version=2} {add=[132 (1428342441392472064)]} 0 4
[junit4:junit4] 2> 21918 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[133 (1428342441399812096)]} 0 0
[junit4:junit4] 2> 21927 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[133 (1428342441405054976)]} 0 1
[junit4:junit4] 2> 21927 T3463 C227 P27714 /update {distrib.from=http://127.0.0.1:27717/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[133 (1428342441405054976)]} 0 4
[junit4:junit4] 2> 21928 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[133]} 0 7
[junit4:junit4] 2> 21931 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[134 (1428342441412395008)]} 0 1
[junit4:junit4] 2> 21934 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[134 (1428342441415540736)]} 0 1
[junit4:junit4] 2> 21937 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[135 (1428342441418686464)]} 0 1
[junit4:junit4] 2> 21945 T3490 C226 P27720 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[135 (1428342441423929344)]} 0 1
[junit4:junit4] 2> 21945 T3463 C227 P27714 /update {distrib.from=http://127.0.0.1:27717/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[135 (1428342441423929344)]} 0 4
[junit4:junit4] 2> 21946 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[135]} 0 7
[junit4:junit4] 2> 21949 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[136 (1428342441431269376)]} 0 1
[junit4:junit4] 2> 21954 T3479 C230 P27717 /update {wt=javabin&version=2} {add=[136 (1428342441436512256)]} 0 2
[junit4:junit4] 2> 21958 T3441 C229 P27710 /update {wt=javabin&version=2} {add=[137 (1428342441440706560)]} 0 1
[junit4:junit4] 2> 21963 T3477 C230 P27717 /update {distrib.from=http://127.0.0.1:27714/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[137 (1428342441445949440)]} 0 1
[junit4:j
[...truncated too long message...]
apache.solr.cloud.BasicDistributedZk2Test-1362173479481/jetty3/index
[junit4:junit4] 2> 87149 T3500 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 87150 T3500 oasc.LeaderElector$1.process WARNING org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election/89271401151660042-4-n_0000000001
[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.delete(ZooKeeper.java:873)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:153)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:150)
[junit4:junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:150)
[junit4:junit4] 2> at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:63)
[junit4:junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:243)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:156)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:100)
[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> 87151 T3500 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> 87151 T3500 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 87151 T3500 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 87151 T3500 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> 87152 T3500 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 87152 T3500 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> 87152 T3500 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {foo_b=PostingsFormat(name=NestedPulsing), n_f1=PostingsFormat(name=TestBloomFilteredLucene41Postings), foo_d=MockVariableIntBlock(baseBlockSize=21), foo_f=PostingsFormat(name=NestedPulsing), n_tl1=PostingsFormat(name=TestBloomFilteredLucene41Postings), n_d1=PostingsFormat(name=Asserting), rnd_b=MockVariableIntBlock(baseBlockSize=21), intDefault=PostingsFormat(name=Asserting), n_td1=PostingsFormat(name=TestBloomFilteredLucene41Postings), timestamp=PostingsFormat(name=Asserting), id=MockVariableIntBlock(baseBlockSize=21), range_facet_sl=PostingsFormat(name=NestedPulsing), range_facet_si=PostingsFormat(name=TestBloomFilteredLucene41Postings), oddField_s=PostingsFormat(name=NestedPulsing), multiDefault=PostingsFormat(name=TestBloomFilteredLucene41Postings), n_tf1=PostingsFormat(name=Asserting), n_dt1=PostingsFormat(name=TestBloomFilteredLucene41Postings), range_facet_l=PostingsFormat(name=Asserting), n_ti1=MockVariableIntBlock(baseBlockSize=21), text=PostingsFormat(name=NestedPulsing), _version_=PostingsFormat(name=Asserting), SubjectTerms_mfacet=PostingsFormat(name=Asserting), a_t=PostingsFormat(name=Asserting), n_tdt1=PostingsFormat(name=Asserting), other_tl1=PostingsFormat(name=Asserting), n_l1=PostingsFormat(name=Asserting), a_si=PostingsFormat(name=TestBloomFilteredLucene41Postings)}, docValues:{timestamp=DocValuesFormat(name=Disk)}, sim=DefaultSimilarity, locale=es_CR, timezone=America/Miquelon
[junit4:junit4] 2> NOTE: FreeBSD 9.0-RELEASE amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=3,free=207319360,total=505085952
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestRealTimeGet, DateFieldTest, CSVRequestHandlerTest, SuggesterTSTTest, TestCharFilters, TestLazyCores, ExternalFileFieldSortTest, CopyFieldTest, IndexReaderFactoryTest, NoCacheHeaderTest, TermVectorComponentTest, RequestHandlersTest, TestSolrDeletionPolicy2, TestBM25SimilarityFactory, DirectUpdateHandlerTest, TestFastLRUCache, QueryEqualityTest, TestSolrJ, ClusterStateTest, URLClassifyProcessorTest, SolrInfoMBeanTest, SliceStateUpdateTest, OverseerTest, SynonymTokenizerTest, ConvertedLegacyTest, TestQueryUtils, TestAnalyzedSuggestions, TestComponentsName, UpdateParamsTest, IndexSchemaTest, ZkSolrClientTest, RecoveryZkTest, FieldMutatingUpdateProcessorTest, TestDistributedGrouping, TestReplicationHandler, TestPluginEnable, CollectionsAPIDistributedZkTest, StatsComponentTest, TestIBSimilarityFactory, JsonLoaderTest, TestElisionMultitermQuery, UniqFieldsUpdateProcessorFactoryTest, TestSolr4Spatial, TestSort, TestStressVersions, StatelessScriptUpdateProcessorFactoryTest, TestNumberUtils, TestCollationField, TestHashPartitioner, JSONWriterTest, ZkNodePropsTest, LeaderElectionTest, TestDocumentBuilder, ChaosMonkeyNothingIsSafeTest, CurrencyFieldOpenExchangeTest, FastVectorHighlighterTest, NotRequiredUniqueKeyTest, TestPerFieldSimilarity, SolrIndexSplitterTest, TestSolrQueryParser, BadIndexSchemaTest, UUIDFieldTest, RequiredFieldsTest, SpellCheckComponentTest, FullSolrCloudDistribCmdsTest, LeaderElectionIntegrationTest, DistributedSpellCheckComponentTest, TestDistributedSearch, SpellCheckCollatorTest, SoftAutoCommitTest, BasicZkTest, SolrCoreTest, IndexBasedSpellCheckerTest, TestMultiCoreConfBootstrap, DirectSolrSpellCheckerTest, PeerSyncTest, QueryElevationComponentTest, BasicFunctionalityTest, SignatureUpdateProcessorFactoryTest, TestJmxIntegration, SampleTest, HighlighterTest, TestTrie, SolrRequestParserTest, TestWordDelimiterFilterFactory, PolyFieldTest, TestCSVResponseWriter, DocumentBuilderTest, TestPseudoReturnFields, BinaryUpdateRequestHandlerTest, TermsComponentTest, TestQueryTypes, PingRequestHandlerTest, TestSurroundQueryParser, DocumentAnalysisRequestHandlerTest, IndexSchemaRuntimeFieldTest, TestReversedWildcardFilterFactory, SearchHandlerTest, SuggesterFSTTest, ShowFileRequestHandlerTest, UpdateRequestProcessorFactoryTest, AlternateDirectoryTest, TestPropInjectDefaults, TestXIncludeConfig, TestDocSet, SolrIndexConfigTest, NumericFieldsTest, MultiTermTest, TestJmxMonitoredMap, EchoParamsTest, TestPhraseSuggestions, TestCodecSupport, PrimUtilsTest, ResourceLoaderTest, TestSystemIdResolver, TestSuggestSpellingConverter, TestLRUCache, SystemInfoHandlerTest, PreAnalyzedFieldTest, CircularListTest, AnalysisAfterCoreReloadTest, TestRandomDVFaceting, BasicDistributedZk2Test]
[junit4:junit4] Completed on J1 in 87.76s, 1 test, 1 error <<< FAILURES!
[...truncated 95 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/build.xml:381: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/build.xml:361: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build.xml:183: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/lucene/common-build.xml:1207: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/lucene/common-build.xml:870: There were test failures: 259 suites, 1085 tests, 1 error, 23 ignored (4 assumptions)
Total time: 47 minutes 23 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure