lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-Tests-trunk-java7 - Build # 3327 - Failure
Date Sun, 21 Oct 2012 05:35:55 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-java7/3327/

2 tests failed.
REGRESSION:  org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch

Error Message:
Test abandoned because suite timeout was reached.

Stack Trace:
java.lang.Exception: Test abandoned because suite timeout was reached.
	at __randomizedtesting.SeedInfo.seed([D1ACC6FED0C1015]:0)


FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.BasicDistributedZk2Test

Error Message:
Suite timeout exceeded (>= 7200000 msec).

Stack Trace:
java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
	at __randomizedtesting.SeedInfo.seed([D1ACC6FED0C1015]:0)




Build Log:
[...truncated 9270 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 5 T1639 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1350790431800
[junit4:junit4]   2> 6 T1639 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 10 T1640 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 11 T1640 oazs.NIOServerCnxn$Factory.<init> binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 12 T1640 oazsp.FileTxnSnapLog.save Snapshotting: 0
[junit4:junit4]   2> 108 T1639 oasc.ZkTestServer.run start zk server on port:46357
[junit4:junit4]   2> 108 T1639 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:46357 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@15bc8fd8
[junit4:junit4]   2> 109 T1645 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:46357
[junit4:junit4]   2> 109 T1639 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 110 T1645 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:46357, initiating session
[junit4:junit4]   2> 111 T1641 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:46358
[junit4:junit4]   2> 111 T1641 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:46358
[junit4:junit4]   2> 111 T1643 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 114 T1643 oazs.NIOServerCnxn.finishSessionInit Established session 0x13a8162443f0000 with negotiated timeout 10000 for client /140.211.11.196:46358
[junit4:junit4]   2> 114 T1645 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:46357, sessionid = 0x13a8162443f0000, negotiated timeout = 10000
[junit4:junit4]   2> 115 T1646 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15bc8fd8 name:ZooKeeperConnection Watcher:127.0.0.1:46357 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 115 T1639 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 115 T1639 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 119 T1644 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x13a8162443f0000
[junit4:junit4]   2> 133 T1646 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 133 T1641 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:46358 which had sessionid 0x13a8162443f0000
[junit4:junit4]   2> 133 T1639 oaz.ZooKeeper.close Session: 0x13a8162443f0000 closed
[junit4:junit4]   2> 134 T1639 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:46357/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@4daed994
[junit4:junit4]   2> 135 T1647 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:46357
[junit4:junit4]   2> 135 T1639 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 136 T1647 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:46357, initiating session
[junit4:junit4]   2> 136 T1641 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:46360
[junit4:junit4]   2> 137 T1641 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:46360
[junit4:junit4]   2> 145 T1643 oazs.NIOServerCnxn.finishSessionInit Established session 0x13a8162443f0001 with negotiated timeout 10000 for client /140.211.11.196:46360
[junit4:junit4]   2> 145 T1647 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:46357, sessionid = 0x13a8162443f0001, negotiated timeout = 10000
[junit4:junit4]   2> 145 T1648 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4daed994 name:ZooKeeperConnection Watcher:127.0.0.1:46357/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 146 T1639 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 146 T1639 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 166 T1639 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 169 T1639 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 177 T1639 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 185 T1639 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 186 T1639 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 202 T1639 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 203 T1639 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 309 T1639 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 310 T1639 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 313 T1639 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 314 T1639 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 326 T1639 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 326 T1639 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 329 T1639 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 330 T1639 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 333 T1639 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 334 T1639 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 336 T1639 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 337 T1639 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 340 T1639 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 341 T1639 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 348 T1639 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 349 T1639 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 352 T1644 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x13a8162443f0001
[junit4:junit4]   2> 353 T1648 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 353 T1639 oaz.ZooKeeper.close Session: 0x13a8162443f0001 closed
[junit4:junit4]   2> 353 T1641 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:46360 which had sessionid 0x13a8162443f0001
[junit4:junit4]   2> 531 T1639 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 535 T1639 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:46361
[junit4:junit4]   2> 536 T1639 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 536 T1639 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1350790432147
[junit4:junit4]   2> 537 T1639 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1350790432147/'
[junit4:junit4]   2> 582 T1639 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 583 T1639 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 583 T1639 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1350790432147
[junit4:junit4]   2> 584 T1639 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1350790432147/solr.xml
[junit4:junit4]   2> 584 T1639 oasc.CoreContainer.<init> New CoreContainer 1688529934
[junit4:junit4]   2> 585 T1639 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1350790432147/'
[junit4:junit4]   2> 585 T1639 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1350790432147/'
[junit4:junit4]   2> 620 T1639 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 637 T1639 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:46357/solr
[junit4:junit4]   2> 638 T1639 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:46357/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@3efa290a
[junit4:junit4]   2> 639 T1658 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:46357
[junit4:junit4]   2> 639 T1639 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 641 T1658 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:46357, initiating session
[junit4:junit4]   2> 641 T1641 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:46363
[junit4:junit4]   2> 641 T1641 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:46363
[junit4:junit4]   2> 643 T1643 oazs.NIOServerCnxn.finishSessionInit Established session 0x13a8162443f0002 with negotiated timeout 5000 for client /140.211.11.196:46363
[junit4:junit4]   2> 643 T1658 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:46357, sessionid = 0x13a8162443f0002, negotiated timeout = 5000
[junit4:junit4]   2> 644 T1659 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3efa290a name:ZooKeeperConnection Watcher:127.0.0.1:46357/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 644 T1639 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 646 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0002 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 656 T1639 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 658 T1639 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46361_solr
[junit4:junit4]   2> 659 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0002 type:delete cxid:0x7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:46361_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:46361_solr
[junit4:junit4]   2> 664 T1639 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46361_solr
[junit4:junit4]   2> 667 T1639 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 668 T1639 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 668 T1639 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 669 T1639 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 669 T1639 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 669 T1639 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 670 T1639 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 670 T1639 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 671 T1639 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 671 T1639 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 688 T1639 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 701 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0002 type:delete cxid:0x15 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 702 T1639 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 709 T1639 oasc.Overseer.start Overseer (id=88525401738903554-127.0.0.1:46361_solr-n_0000000000) starting
[junit4:junit4]   2> 709 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0002 type:create cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 711 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0002 type:create cxid:0x1b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 712 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0002 type:create cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 721 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0002 type:create cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 723 T1661 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 723 T1639 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 733 T1639 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 735 T1660 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 740 T1639 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1350790432147/collection1
[junit4:junit4]   2> 741 T1639 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 742 T1639 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 742 T1639 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 744 T1639 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1350790432147/collection1/'
[junit4:junit4]   2> 745 T1639 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1350790432147/collection1/lib/README' to classloader
[junit4:junit4]   2> 746 T1639 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1350790432147/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 804 T1639 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 878 T1639 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 980 T1639 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 995 T1639 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1757 T1639 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1774 T1639 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1778 T1639 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1805 T1639 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1810 T1639 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1815 T1639 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1816 T1639 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1817 T1639 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1350790432147/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/control/data/
[junit4:junit4]   2> 1818 T1639 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4e3ceb07
[junit4:junit4]   2> 1824 T1639 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/control/data/index/
[junit4:junit4]   2> 1825 T1639 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1826 T1639 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/control/data/index forceNew:false
[junit4:junit4]   2> 1848 T1639 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2bfbe8ef; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1849 T1639 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 1863 T1639 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 1865 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1866 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 1866 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1867 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 1868 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1868 T1639 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1869 T1639 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1869 T1639 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1870 T1639 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1871 T1639 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 1871 T1639 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 1872 T1639 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1872 T1639 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 1873 T1639 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 1873 T1639 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 1874 T1639 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1875 T1639 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1875 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1876 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1876 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1877 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1877 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1878 T1639 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1879 T1639 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 1879 T1639 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 1894 T1639 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1899 T1639 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 1900 T1639 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 1905 T1639 oass.SolrIndexSearcher.<init> Opening Searcher@55805264 main
[junit4:junit4]   2> 1906 T1639 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1906 T1639 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1907 T1639 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 1929 T1639 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 2021 T1662 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@55805264 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 2026 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0002 type:create cxid:0x56 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4]   2> 2030 T1639 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 2031 T1639 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:46361/solr shardId:control_shard
[junit4:junit4]   2> 2031 T1639 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/control_shard/election
[junit4:junit4]   2> 2037 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0002 type:delete cxid:0x65 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 2038 T1639 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 2038 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0002 type:create cxid:0x66 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2243 T1660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2244 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0002 type:create cxid:0x6d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 2275 T1659 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2541 T1639 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2542 T1639 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2543 T1639 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:46361/solr/collection1/
[junit4:junit4]   2> 2543 T1639 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 2544 T1639 oasc.SyncStrategy.syncToMe http://127.0.0.1:46361/solr/collection1/ has no replicas
[junit4:junit4]   2> 2544 T1639 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:46361/solr/collection1/
[junit4:junit4]   2> 2545 T1639 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/control_shard
[junit4:junit4]   2> 2553 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0002 type:create cxid:0x8b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2779 T1660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2794 T1659 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2821 T1639 oasc.ZkController.register We are http://127.0.0.1:46361/solr/collection1/ and leader is http://127.0.0.1:46361/solr/collection1/
[junit4:junit4]   2> 2821 T1639 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:46361/solr
[junit4:junit4]   2> 2822 T1639 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 2824 T1639 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2824 T1639 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0
[junit4:junit4]   2> 2825 T1639 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 2825 T1639 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 3016 T1639 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 3019 T1639 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:46368
[junit4:junit4]   2> 3020 T1639 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3020 T1639 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1350790434634
[junit4:junit4]   2> 3021 T1639 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1350790434634/'
[junit4:junit4]   2> 3070 T1639 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 3071 T1639 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3071 T1639 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1350790434634
[junit4:junit4]   2> 3072 T1639 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1350790434634/solr.xml
[junit4:junit4]   2> 3072 T1639 oasc.CoreContainer.<init> New CoreContainer 1109643940
[junit4:junit4]   2> 3073 T1639 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1350790434634/'
[junit4:junit4]   2> 3074 T1639 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1350790434634/'
[junit4:junit4]   2> 3106 T1639 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 3123 T1639 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:46357/solr
[junit4:junit4]   2> 3124 T1639 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:46357/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@468d71ad
[junit4:junit4]   2> 3125 T1672 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:46357
[junit4:junit4]   2> 3125 T1639 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3126 T1672 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:46357, initiating session
[junit4:junit4]   2> 3127 T1641 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:46370
[junit4:junit4]   2> 3127 T1641 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:46370
[junit4:junit4]   2> 3129 T1643 oazs.NIOServerCnxn.finishSessionInit Established session 0x13a8162443f0003 with negotiated timeout 5000 for client /140.211.11.196:46370
[junit4:junit4]   2> 3129 T1672 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:46357, sessionid = 0x13a8162443f0003, negotiated timeout = 5000
[junit4:junit4]   2> 3129 T1673 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@468d71ad name:ZooKeeperConnection Watcher:127.0.0.1:46357/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3129 T1639 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3130 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0003 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3132 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0003 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3133 T1639 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46368_solr
[junit4:junit4]   2> 3134 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0003 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:46368_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:46368_solr
[junit4:junit4]   2> 3142 T1639 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46368_solr
[junit4:junit4]   2> 3144 T1659 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 3145 T1639 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 3146 T1639 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 3146 T1639 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 3146 T1639 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 3147 T1639 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 3147 T1639 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 3148 T1639 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 3148 T1639 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 3149 T1639 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 3149 T1639 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 3165 T1639 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3172 T1639 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1350790434634/collection1
[junit4:junit4]   2> 3172 T1639 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 3173 T1639 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 3173 T1639 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 3175 T1639 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1350790434634/collection1/'
[junit4:junit4]   2> 3176 T1639 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1350790434634/collection1/lib/README' to classloader
[junit4:junit4]   2> 3177 T1639 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1350790434634/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 3234 T1639 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 3298 T1660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3308 T1639 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 3314 T1673 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3314 T1659 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3315 T1639 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 3328 T1639 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 3931 T1639 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 3956 T1639 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 3960 T1639 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 3972 T1639 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 3977 T1639 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 3983 T1639 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 3984 T1639 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 3985 T1639 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1350790434634/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty1/
[junit4:junit4]   2> 3986 T1639 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4e3ceb07
[junit4:junit4]   2> 3987 T1639 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty1/index/
[junit4:junit4]   2> 3988 T1639 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 3989 T1639 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty1/index forceNew:false
[junit4:junit4]   2> 3995 T1639 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@110ea5dc; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 3996 T1639 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 3997 T1639 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 3999 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 3999 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 4000 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 4000 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 4001 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 4002 T1639 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 4002 T1639 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 4003 T1639 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 4004 T1639 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 4004 T1639 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 4005 T1639 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 4006 T1639 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 4006 T1639 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 4007 T1639 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 4007 T1639 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 4008 T1639 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 4009 T1639 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4009 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4010 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4010 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4011 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4012 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4012 T1639 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4013 T1639 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 4014 T1639 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 4026 T1639 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 4031 T1639 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 4032 T1639 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 4035 T1639 oass.SolrIndexSearcher.<init> Opening Searcher@220f4d21 main
[junit4:junit4]   2> 4036 T1639 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 4037 T1639 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 4038 T1639 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 4044 T1639 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 4121 T1674 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@220f4d21 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 4320 T1660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4327 T1659 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4327 T1673 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4627 T1639 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 4627 T1639 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:46368/solr shardId:shard1
[junit4:junit4]   2> 4629 T1639 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 4647 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0003 type:delete cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 4648 T1639 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 4649 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0003 type:create cxid:0x44 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4659 T1639 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 4659 T1639 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 4660 T1639 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:46368/solr/collection1/
[junit4:junit4]   2> 4660 T1639 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 4661 T1639 oasc.SyncStrategy.syncToMe http://127.0.0.1:46368/solr/collection1/ has no replicas
[junit4:junit4]   2> 4661 T1639 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:46368/solr/collection1/
[junit4:junit4]   2> 4662 T1639 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 4666 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0003 type:create cxid:0x4e zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4838 T1660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4858 T1659 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4858 T1673 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4880 T1639 oasc.ZkController.register We are http://127.0.0.1:46368/solr/collection1/ and leader is http://127.0.0.1:46368/solr/collection1/
[junit4:junit4]   2> 4880 T1639 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:46368/solr
[junit4:junit4]   2> 4881 T1639 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 4882 T1639 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4883 T1639 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0
[junit4:junit4]   2> 4884 T1639 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 4884 T1639 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 5057 T1639 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 5060 T1639 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:46375
[junit4:junit4]   2> 5061 T1639 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 5062 T1639 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1350790436692
[junit4:junit4]   2> 5062 T1639 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1350790436692/'
[junit4:junit4]   2> 5111 T1639 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 5111 T1639 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 5112 T1639 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1350790436692
[junit4:junit4]   2> 5112 T1639 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1350790436692/solr.xml
[junit4:junit4]   2> 5113 T1639 oasc.CoreContainer.<init> New CoreContainer 145406564
[junit4:junit4]   2> 5113 T1639 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1350790436692/'
[junit4:junit4]   2> 5114 T1639 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1350790436692/'
[junit4:junit4]   2> 5149 T1639 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 5167 T1639 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:46357/solr
[junit4:junit4]   2> 5168 T1639 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:46357/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@8107079
[junit4:junit4]   2> 5169 T1684 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:46357
[junit4:junit4]   2> 5169 T1639 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 5170 T1684 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:46357, initiating session
[junit4:junit4]   2> 5170 T1641 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:46376
[junit4:junit4]   2> 5171 T1641 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:46376
[junit4:junit4]   2> 5173 T1643 oazs.NIOServerCnxn.finishSessionInit Established session 0x13a8162443f0004 with negotiated timeout 5000 for client /140.211.11.196:46376
[junit4:junit4]   2> 5173 T1684 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:46357, sessionid = 0x13a8162443f0004, negotiated timeout = 5000
[junit4:junit4]   2> 5173 T1685 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8107079 name:ZooKeeperConnection Watcher:127.0.0.1:46357/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 5174 T1639 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 5175 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0004 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5183 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0004 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5184 T1639 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46375_solr
[junit4:junit4]   2> 5185 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0004 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:46375_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:46375_solr
[junit4:junit4]   2> 5186 T1639 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46375_solr
[junit4:junit4]   2> 5194 T1673 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 5194 T1659 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 5195 T1639 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 5196 T1639 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 5196 T1639 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 5197 T1639 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 5197 T1639 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 5197 T1639 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 5198 T1639 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 5198 T1639 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 5199 T1639 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 5199 T1639 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 5217 T1639 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 5224 T1639 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1350790436692/collection1
[junit4:junit4]   2> 5225 T1639 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 5225 T1639 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 5226 T1639 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 5227 T1639 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1350790436692/collection1/'
[junit4:junit4]   2> 5229 T1639 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1350790436692/collection1/lib/README' to classloader
[junit4:junit4]   2> 5229 T1639 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1350790436692/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 5286 T1639 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 5361 T1639 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 5363 T1660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5377 T1659 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5377 T1673 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5462 T1685 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5462 T1639 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 5473 T1639 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 6077 T1639 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 6085 T1639 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 6088 T1639 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 6098 T1639 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6102 T1639 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6106 T1639 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6107 T1639 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6108 T1639 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1350790436692/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty2/
[junit4:junit4]   2> 6108 T1639 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4e3ceb07
[junit4:junit4]   2> 6109 T1639 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty2/index/
[junit4:junit4]   2> 6110 T1639 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 6111 T1639 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty2/index forceNew:false
[junit4:junit4]   2> 6116 T1639 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@8c85d6b; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 6116 T1639 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 6122 T1639 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 6123 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 6124 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 6124 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 6124 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 6125 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 6125 T1639 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 6126 T1639 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 6126 T1639 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 6127 T1639 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 6127 T1639 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 6128 T1639 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 6128 T1639 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 6129 T1639 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 6129 T1639 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 6129 T1639 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 6130 T1639 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 6130 T1639 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6131 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6131 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6132 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6132 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6133 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6133 T1639 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6134 T1639 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 6134 T1639 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 6143 T1639 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 6146 T1639 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 6147 T1639 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 6150 T1639 oass.SolrIndexSearcher.<init> Opening Searcher@5c40c3d0 main
[junit4:junit4]   2> 6151 T1639 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 6151 T1639 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 6152 T1639 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 6182 T1639 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 6226 T1686 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5c40c3d0 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 6383 T1660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6407 T1659 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6407 T1685 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6407 T1673 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6731 T1639 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 6731 T1639 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:46375/solr shardId:shard2
[junit4:junit4]   2> 6732 T1639 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 6764 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0004 type:delete cxid:0x42 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard2 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard2
[junit4:junit4]   2> 6765 T1639 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 6766 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0004 type:create cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6783 T1639 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 6784 T1639 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 6784 T1639 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:46375/solr/collection1/
[junit4:junit4]   2> 6785 T1639 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 6785 T1639 oasc.SyncStrategy.syncToMe http://127.0.0.1:46375/solr/collection1/ has no replicas
[junit4:junit4]   2> 6786 T1639 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:46375/solr/collection1/
[junit4:junit4]   2> 6786 T1639 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 6789 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0004 type:create cxid:0x4c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6911 T1660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6931 T1659 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6931 T1673 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6931 T1685 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6952 T1639 oasc.ZkController.register We are http://127.0.0.1:46375/solr/collection1/ and leader is http://127.0.0.1:46375/solr/collection1/
[junit4:junit4]   2> 6952 T1639 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:46375/solr
[junit4:junit4]   2> 6952 T1639 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 6954 T1639 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6955 T1639 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0
[junit4:junit4]   2> 6955 T1639 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 6955 T1639 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 7097 T1639 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 7100 T1639 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:46381
[junit4:junit4]   2> 7100 T1639 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 7101 T1639 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1350790438760
[junit4:junit4]   2> 7101 T1639 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1350790438760/'
[junit4:junit4]   2> 7134 T1639 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 7134 T1639 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 7134 T1639 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1350790438760
[junit4:junit4]   2> 7135 T1639 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1350790438760/solr.xml
[junit4:junit4]   2> 7135 T1639 oasc.CoreContainer.<init> New CoreContainer 2024499764
[junit4:junit4]   2> 7136 T1639 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1350790438760/'
[junit4:junit4]   2> 7136 T1639 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1350790438760/'
[junit4:junit4]   2> 7161 T1639 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 7173 T1639 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:46357/solr
[junit4:junit4]   2> 7174 T1639 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:46357/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@32ead0a8
[junit4:junit4]   2> 7175 T1696 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:46357
[junit4:junit4]   2> 7175 T1639 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 7176 T1696 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:46357, initiating session
[junit4:junit4]   2> 7176 T1641 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:46382
[junit4:junit4]   2> 7176 T1641 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:46382
[junit4:junit4]   2> 7180 T1643 oazs.NIOServerCnxn.finishSessionInit Established session 0x13a8162443f0005 with negotiated timeout 5000 for client /140.211.11.196:46382
[junit4:junit4]   2> 7180 T1696 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:46357, sessionid = 0x13a8162443f0005, negotiated timeout = 5000
[junit4:junit4]   2> 7180 T1697 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32ead0a8 name:ZooKeeperConnection Watcher:127.0.0.1:46357/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 7180 T1639 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 7181 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0005 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7213 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0005 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7226 T1639 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46381_solr
[junit4:junit4]   2> 7227 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0005 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:46381_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:46381_solr
[junit4:junit4]   2> 7228 T1639 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46381_solr
[junit4:junit4]   2> 7239 T1673 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7239 T1659 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7239 T1685 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7240 T1639 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 7240 T1639 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 7241 T1639 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 7241 T1639 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 7242 T1639 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 7242 T1639 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 7243 T1639 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 7243 T1639 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 7244 T1639 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 7244 T1639 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 7262 T1639 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 7269 T1639 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1350790438760/collection1
[junit4:junit4]   2> 7270 T1639 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 7270 T1639 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 7271 T1639 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 7272 T1639 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1350790438760/collection1/'
[junit4:junit4]   2> 7274 T1639 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1350790438760/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 7274 T1639 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1350790438760/collection1/lib/README' to classloader
[junit4:junit4]   2> 7328 T1639 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 7402 T1639 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 7443 T1660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7458 T1673 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7458 T1659 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7458 T1685 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7503 T1697 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7503 T1639 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 7515 T1639 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 8209 T1639 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 8221 T1639 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 8225 T1639 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 8241 T1639 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8248 T1639 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8253 T1639 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8255 T1639 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8256 T1639 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1350790438760/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty3/
[junit4:junit4]   2> 8256 T1639 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4e3ceb07
[junit4:junit4]   2> 8264 T1639 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty3/index/
[junit4:junit4]   2> 8264 T1639 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 8265 T1639 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty3/index forceNew:false
[junit4:junit4]   2> 8287 T1639 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2aa21f25; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 8288 T1639 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 8302 T1639 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 8304 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 8305 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 8305 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 8306 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 8307 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 8307 T1639 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 8308 T1639 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 8308 T1639 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 8309 T1639 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 8310 T1639 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 8310 T1639 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 8311 T1639 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 8312 T1639 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 8312 T1639 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 8313 T1639 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 8313 T1639 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 8314 T1639 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8315 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8315 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8316 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8317 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8317 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8318 T1639 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8319 T1639 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 8319 T1639 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 8334 T1639 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 8339 T1639 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 8341 T1639 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 8344 T1639 oass.SolrIndexSearcher.<init> Opening Searcher@9818365 main
[junit4:junit4]   2> 8346 T1639 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 8346 T1639 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 8347 T1639 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 8376 T1639 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 8492 T1698 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9818365 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 8966 T1660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8991 T1659 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8991 T1697 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8991 T1685 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8991 T1673 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9000 T1639 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 9000 T1639 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:46381/solr shardId:shard1
[junit4:junit4]   2> 9010 T1639 oasc.ZkController.register We are http://127.0.0.1:46381/solr/collection1/ and leader is http://127.0.0.1:46368/solr/collection1/
[junit4:junit4]   2> 9011 T1639 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:46381/solr
[junit4:junit4]   2> 9011 T1639 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 9012 T1639 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C211 name=collection1 org.apache.solr.core.SolrCore@48375 url=http://127.0.0.1:46381/solr/collection1 node=127.0.0.1:46381_solr
[junit4:junit4]   2> 9013 T1699 C211 P46381 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 9013 T1639 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9718 T1699 C211 P46381 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 9719 T1639 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0
[junit4:junit4]   2> 9720 T1699 C211 P46381 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:46368/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 9720 T1639 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 9720 T1699 C211 P46381 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:46381/solr START replicas=[http://127.0.0.1:46368/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 9721 T1639 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 9721 T1660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9721 T1699 C211 P46381 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 9722 T1699 C211 P46381 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 9723 T1699 C211 P46381 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 9723 T1699 C211 P46381 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C212 name=collection1 org.apache.solr.core.SolrCore@50c3c2fa url=http://127.0.0.1:46368/solr/collection1 node=127.0.0.1:46368_solr
[junit4:junit4]   2> 9730 T1665 C212 P46368 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 9735 T1659 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9735 T1673 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9735 T1685 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9735 T1697 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9856 T1639 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 9858 T1639 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:46388
[junit4:junit4]   2> 9859 T1639 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 9859 T1639 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1350790441529
[junit4:junit4]   2> 9859 T1639 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1350790441529/'
[junit4:junit4]   2> 9888 T1639 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 9889 T1639 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 9889 T1639 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1350790441529
[junit4:junit4]   2> 9889 T1639 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1350790441529/solr.xml
[junit4:junit4]   2> 9890 T1639 oasc.CoreContainer.<init> New CoreContainer 586185529
[junit4:junit4]   2> 9890 T1639 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1350790441529/'
[junit4:junit4]   2> 9890 T1639 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1350790441529/'
[junit4:junit4]   2> 9914 T1639 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 9927 T1639 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:46357/solr
[junit4:junit4]   2> 9928 T1639 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:46357/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@552508b
[junit4:junit4]   2> 9928 T1710 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:46357
[junit4:junit4]   2> 9928 T1639 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 9929 T1710 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:46357, initiating session
[junit4:junit4]   2> 9930 T1641 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:46390
[junit4:junit4]   2> 9930 T1641 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:46390
[junit4:junit4]   2> 9937 T1643 oazs.NIOServerCnxn.finishSessionInit Established session 0x13a8162443f0006 with negotiated timeout 5000 for client /140.211.11.196:46390
[junit4:junit4]   2> 9937 T1710 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:46357, sessionid = 0x13a8162443f0006, negotiated timeout = 5000
[junit4:junit4]   2> 9937 T1711 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@552508b name:ZooKeeperConnection Watcher:127.0.0.1:46357/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 9937 T1639 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 9938 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0006 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 9957 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0006 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 9962 T1639 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46388_solr
[junit4:junit4]   2> 9962 T1644 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13a8162443f0006 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:46388_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:46388_solr
[junit4:junit4]   2> 9970 T1639 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46388_solr
[junit4:junit4]   2> 10004 T1685 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 10004 T1659 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 10003 T1673 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 10003 T1697 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 10004 T1639 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 10005 T1639 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 10005 T1639 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 10005 T1639 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 10006 T1639 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 10006 T1639 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 10006 T1639 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 10007 T1639 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 10007 T1639 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 10007 T1639 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 10025 T1639 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 10031 T1639 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1350790441529/collection1
[junit4:junit4]   2> 10031 T1639 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 10031 T1639 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 10032 T1639 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 10033 T1639 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1350790441529/collection1/'
[junit4:junit4]   2> 10034 T1639 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1350790441529/collection1/lib/README' to classloader
[junit4:junit4]   2> 10035 T1639 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1350790441529/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 10075 T1639 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 10130 T1639 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 10231 T1639 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 10239 T1639 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 10699 T1639 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 10707 T1639 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 10710 T1639 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 10720 T1639 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10724 T1639 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10727 T1639 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10728 T1639 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10729 T1639 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1350790441529/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty4/
[junit4:junit4]   2> 10730 T1639 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4e3ceb07
[junit4:junit4]   2> 10731 T1639 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty4/index/
[junit4:junit4]   2> 10731 T1639 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 10732 T1639 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty4/index forceNew:false
[junit4:junit4]   2> 10737 T1639 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@3909c794; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10738 T1639 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 10749 T1639 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 10751 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 10751 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 10752 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 10752 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 10753 T1639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 10753 T1639 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 10754 T1639 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 10754 T1639 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 10755 T1639 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 10755 T1639 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 10756 T1639 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 10756 T1639 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 10757 T1639 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 10757 T1639 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 10757 T1639 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 10758 T1639 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 10758 T1639 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10759 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10759 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10760 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10760 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10761 T1639 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10761 T1639 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10762 T1639 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 10762 T1639 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 10771 T1639 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 10775 T1639 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 10776 T1639 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 10779 T1639 oass.SolrIndexSearcher.<init> Opening Searcher@35d711b2 main
[junit4:junit4]   2> 10780 T1639 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 10780 T1639 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 10781 T1639 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 10802 T1639 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 10896 T1712 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@35d711b2 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 11242 T1660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11436 T1673 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11436 T1659 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11436 T1697 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11436 T1685 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11436 T1711 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2>  C211_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:46381_solr, base_url=http://127.0.0.1:46381/solr}
[junit4:junit4]   2> 11738 T1699 C211 P46381 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 11738 T1699 C211 P46381 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 11738 T1699 C211 P46381 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:46368/solr/collection1/. core=collection1
[junit4:junit4]   2> 11739 T1699 C211 P46381 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 11756 T1667 C212 P46368 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 11762 T1667 C212 P46368 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@110ea5dc; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 11763 T1667 C212 P46368 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 11764 T1667 C212 P46368 oass.SolrIndexSearcher.<init> Opening Searcher@4057d072 realtime
[junit4:junit4]   2> 11764 T1667 C212 P46368 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 11765 T1667 C212 P46368 /update {waitSearcher=true&openSearcher=false&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 9
[junit4:junit4]   2> 11766 T1699 C211 P46381 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 11766 T1699 C211 P46381 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 11768 T1668 C212 P46368 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 11768 T1668 C212 P46368 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 11778 T1699 C211 P46381 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2aa21f25; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 11778 T1699 C211 P46381 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 11778 T1699 C211 P46381 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 11783 T1699 C211 P46381 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2aa21f25; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2aa21f25; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 11783 T1699 C211 P46381 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 11785 T1699 C211 P46381 oass.SolrIndexSearcher.<init> Opening Searcher@40f80531 main
[junit4:junit4]   2> 11785 T1699 C211 P46381 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 11787 T1698 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@40f80531 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 11787 T1699 C211 P46381 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 11787 T1699 C211 P46381 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 11810 T1699 C211 P46381 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 11903 T1639 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 11903 T1639 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:46388/solr shardId:shard2
[junit4:junit4]   2> 11912 T1639 oasc.ZkController.register We are http://127.0.0.1:46388/solr/collection1/ and leader is http://127.0.0.1:46375/solr/collection1/
[junit4:junit4]   2> 11912 T1639 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:46388/solr
[junit4:junit4]   2> 11913 T1639 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 11913 T1639 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C213 name=collection1 org.apache.solr.core.SolrCore@1cdce97 url=http://127.0.0.1:46388/solr/collection1 node=127.0.0.1:46388_solr
[junit4:junit4]   2> 11914 T1713 C213 P46388 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 11914 T1713 C213 P46388 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 11914 T1639 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11915 T1639 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0
[junit4:junit4]   2> 11915 T1639 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 11916 T1639 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 11922 T1713 C213 P46388 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:46375/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 11922 T1713 C213 P46388 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:46388/solr START replicas=[http://127.0.0.1:46375/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 11922 T1713 C213 P46388 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 11923 T1713 C213 P46388 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 11923 T1713 C213 P46388 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 11923 T1713 C213 P46388 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 11928 T1639 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:46357/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@3472f25d
[junit4:junit4]   2> 11929 T1715 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:46357
[junit4:junit4]   2> 11929 T1639 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 11930 T1715 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:46357, initiating session
[junit4:junit4]   2> 11930 T1641 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:46398
[junit4:junit4]   2> 11930 T1641 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:46398
[junit4:junit4]   2> ASYNC  NEW_CORE C214 name=collection1 org.apache.solr.core.SolrCore@7e39adee url=http://127.0.0.1:46375/solr/collection1 node=127.0.0.1:46375_solr
[junit4:junit4]   2> 11931 T1677 C214 P46375 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=0 
[junit4:junit4]   2> 11971 T1643 oazs.NIOServerCnxn.finishSessionInit Established session 0x13a8162443f0007 with negotiated timeout 10000 for client /140.211.11.196:46398
[junit4:junit4]   2> 11971 T1715 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:46357, sessionid = 0x13a8162443f0007, negotiated timeout = 10000
[junit4:junit4]   2> 11971 T1716 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3472f25d name:ZooKeeperConnection Watcher:127.0.0.1:46357/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 11971 T1639 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 11973 T1639 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 11975 T1639 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 11975 T1639 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 11989 T1639 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> ASYNC  NEW_CORE C215 name=collection1 org.apache.solr.core.SolrCore@4113cd8a url=http://127.0.0.1:46361/solr/collection1 node=127.0.0.1:46361_solr
[junit4:junit4]   2> 12012 T1651 C215 P46361 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2bfbe8ef; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 12013 T1651 C215 P46361 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 12017 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[1 (1416406440386494464)]} 0 22
[junit4:junit4]   2> 12017 T1639 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:46357/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@2e49b1d
[junit4:junit4]   2> 12019 T1717 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:46357
[junit4:junit4]   2> 12019 T1639 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12019 T1717 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:46357, initiating session
[junit4:junit4]   2> 12019 T1641 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:46401
[junit4:junit4]   2> 12020 T1641 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:46401
[junit4:junit4]   2> 12025 T1643 oazs.NIOServerCnxn.finishSessionInit Established session 0x13a8162443f0008 with negotiated timeout 10000 for client /140.211.11.196:46401
[junit4:junit4]   2> 12025 T1717 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:46357, sessionid = 0x13a8162443f0008, negotiated timeout = 10000
[junit4:junit4]   2> 12025 T1718 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e49b1d name:ZooKeeperConnection Watcher:127.0.0.1:46357/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12025 T1639 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12026 T1639 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 12042 T1660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12059 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=13 
[junit4:junit4]   2> 12060 T1669 C212 P46368 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=29 
[junit4:junit4]   2> 12061 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[1]} 0 32
[junit4:junit4]   2> 12062 T1639 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):1800
[junit4:junit4]   2> 12090 T1639 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12091 T1718 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12091 T1716 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12091 T1685 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12091 T1673 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12091 T1697 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12091 T1711 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12091 T1659 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 13093 T1639 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14095 T1639 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C213_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:46388_solr, base_url=http://127.0.0.1:46388/solr}
[junit4:junit4]   2> 14939 T1713 C213 P46388 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 14939 T1713 C213 P46388 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 14939 T1713 C213 P46388 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:46375/solr/collection1/. core=collection1
[junit4:junit4]   2> 14939 T1713 C213 P46388 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 14956 T1680 C214 P46375 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 14971 T1680 C214 P46375 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@8c85d6b; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 14972 T1680 C214 P46375 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 14973 T1680 C214 P46375 oass.SolrIndexSearcher.<init> Opening Searcher@5e14db9b realtime
[junit4:junit4]   2> 14974 T1680 C214 P46375 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 14974 T1680 C214 P46375 /update {waitSearcher=true&openSearcher=false&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 18
[junit4:junit4]   2> 14975 T1713 C213 P46388 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 14975 T1713 C213 P46388 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 14977 T1681 C214 P46375 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 14978 T1681 C214 P46375 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14989 T1713 C213 P46388 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@3909c794; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 14990 T1713 C213 P46388 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 14991 T1713 C213 P46388 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 14995 T1713 C213 P46388 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@3909c794; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@3909c794; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 14995 T1713 C213 P46388 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 14999 T1713 C213 P46388 oass.SolrIndexSearcher.<init> Opening Searcher@63dd54e1 main
[junit4:junit4]   2> 15000 T1713 C213 P46388 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15001 T1712 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@63dd54e1 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 15001 T1713 C213 P46388 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 15002 T1713 C213 P46388 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 15014 T1713 C213 P46388 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 15097 T1639 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15113 T1660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15130 T1659 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15130 T1716 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15131 T1685 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15131 T1697 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15131 T1673 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15131 T1718 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15130 T1711 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 16099 T1639 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16104 T1651 C215 P46361 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16235 T1651 C215 P46361 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2bfbe8ef; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2bfbe8ef; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Lucene41WithOrds_0.tib, _0_Asserting_0.tim, _0_Asserting_0.tip, _0_MockSep_0.pos, _0_Lucene41WithOrds_0.tii, _0_Lucene41WithOrds_0.pos, _0_MockSep_0.skp, _0.si, _0_MockSep_0.doc, _0_Asserting_0.doc, _0_MockRandom_0.tib, _0.fnm, _0_Lucene41WithOrds_0.doc, _0_nrm.cfs, _0_MockSep_0.tib, _0_MockRandom_0.sd, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0_nrm.cfe, segments_2, _0_MockSep_0.frq, _0_MockRandom_0.tii, _0.fdx, _0_MockSep_0.tii, _0_MockSep_0.pyl, _0_Asserting_0.pos, _0.fdt]
[junit4:junit4]   2> 16235 T1651 C215 P46361 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 16255 T1651 C215 P46361 oass.SolrIndexSearcher.<init> Opening Searcher@63297458 main
[junit4:junit4]   2> 16255 T1651 C215 P46361 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16257 T1662 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@63297458 main{StandardDirectoryReader(segments_2:3 _0(5.0):C1)}
[junit4:junit4]   2> 16258 T1651 C215 P46361 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 155
[junit4:junit4]   2> 16260 T1670 C212 P46368 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16374 T1670 C212 P46368 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@110ea5dc; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@110ea5dc; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Asserting_0.tim, _0_Lucene41WithOrds_0.tib, _0_Asserting_0.tip, _0_MockSep_0.pos, _0_Lucene41WithOrds_0.tii, _0_Lucene41WithOrds_0.pos, _0_MockSep_0.skp, _0.si, _0_MockSep_0.doc, _0_Asserting_0.doc, _0_MockRandom_0.tib, _0.fnm, _0_Lucene41WithOrds_0.doc, _0_nrm.cfs, _0_MockRandom_0.skp, _0_MockSep_0.tib, _0_MockRandom_0.sd, _0_MockRandom_0.frq, _0_MockRandom_0.tiv, _0_MockRandom_0.doc, _0_nrm.cfe, _0_MockRandom_0.pos, segments_2, _0_MockSep_0.frq, _0.fdx, _0_MockSep_0.tii, _0_MockRandom_0.pyl, _0_MockSep_0.pyl, _0_Asserting_0.pos, _0.fdt]
[junit4:junit4]   2> 16375 T1670 C212 P46368 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 16387 T1670 C212 P46368 oass.SolrIndexSearcher.<init> Opening Searcher@2c8e6076 main
[junit4:junit4]   2> 16388 T1670 C212 P46368 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16389 T1674 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2c8e6076 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 16390 T1670 C212 P46368 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:46381/solr/collection1/, StdNode: http://127.0.0.1:46375/solr/collection1/, StdNode: http://127.0.0.1:46388/solr/collection1/]
[junit4:junit4]   2> 16392 T1682 C214 P46375 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2>  C211_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:46381_solr, base_url=http://127.0.0.1:46381/solr}
[junit4:junit4]   2> 16392 T1689 C211 P46381 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16394 T1682 C214 P46375 oass.SolrIndexSearcher.<init> Opening Searcher@2bae6fbb main
[junit4:junit4]   2> 16395 T1682 C214 P46375 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16396 T1686 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2bae6fbb main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4:junit4]   2> 16396 T1682 C214 P46375 /update {waitSearcher=true&commit=true&commit_end_point=true&expungeDeletes=false&wt=javabin&softCommit=false&version=2} {commit=} 0 4
[junit4:junit4]   2>  C213_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:46388_solr, base_url=http://127.0.0.1:46388/solr}
[junit4:junit4]   2> 16415 T1703 C213 P46388 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16422 T1703 C213 P46388 oass.SolrIndexSearcher.<init> Opening Searcher@8269ffd main
[junit4:junit4]   2> 16422 T1703 C213 P46388 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16424 T1712 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@8269ffd main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 16425 T1703 C213 P46388 /update {waitSearcher=true&commit=true&commit_end_point=true&expungeDeletes=false&wt=javabin&softCommit=false&version=2} {commit=} 0 10
[junit4:junit4]   2> 16676 T1689 C211 P46381 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2aa21f25; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2aa21f25; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[_0_Lucene41WithOrds_0.tib, _0_Asserting_0.tim, _0_Asserting_0.tip, _0_MockSep_0.pos, _0_Lucene41WithOrds_0.tii, _0_Lucene41WithOrds_0.pos, _0_MockSep_0.skp, _0.si, _0_MockSep_0.doc, _0_Asserting_0.doc, _0_MockRandom_0.tib, _0.fnm, _0_Lucene41WithOrds_0.doc, _0_nrm.cfs, _0_MockSep_0.tib, _0_MockRandom_0.sd, _0_MockRandom_0.tiv, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0_nrm.cfe, _0_MockSep_0.frq, _0.fdx, _0_MockSep_0.tii, _0_MockSep_0.pyl, _0_Asserting_0.pos, _0.fdt, segments_3]
[junit4:junit4]   2> 16677 T1689 C211 P46381 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 16694 T1689 C211 P46381 oass.SolrIndexSearcher.<init> Opening Searcher@52edf86e main
[junit4:junit4]   2> 16695 T1689 C211 P46381 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16696 T1698 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@52edf86e main{StandardDirectoryReader(segments_3:4 _0(5.0):C1)}
[junit4:junit4]   2> 16696 T1689 C211 P46381 /update {waitSearcher=true&commit=true&commit_end_point=true&expungeDeletes=false&wt=javabin&softCommit=false&version=2} {commit=} 0 304
[junit4:junit4]   2> 16697 T1670 C212 P46368 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 437
[junit4:junit4]   2> 16704 T1652 C215 P46361 REQ /select {fl=id,score&shard.url=127.0.0.1:46361/solr/collection1/&NOW=1350790448494&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 16707 T1652 C215 P46361 REQ /select {shard.url=127.0.0.1:46361/solr/collection1/&NOW=1350790448494&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16708 T1651 C215 P46361 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=8 
[junit4:junit4]   2> 16709 T1639 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:46357/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@2b98763e
[junit4:junit4]   2> 16710 T1724 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:46357
[junit4:junit4]   2> 16710 T1639 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 16711 T1724 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:46357, initiating session
[junit4:junit4]   2> 16711 T1641 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:46420
[junit4:junit4]   2> 16711 T1641 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:46420
[junit4:junit4]   2> 16716 T1643 oazs.NIOServerCnxn.finishSessionInit Established session 0x13a8162443f0009 with negotiated timeout 10000 for client /140.211.11.196:46420
[junit4:junit4]   2> 16716 T1724 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:46357, sessionid = 0x13a8162443f0009, negotiated timeout = 10000
[junit4:junit4]   2> 16716 T1725 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2b98763e name:ZooKeeperConnection Watcher:127.0.0.1:46357/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 16716 T1639 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 16717 T1639 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 16719 T1644 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x13a8162443f0009
[junit4:junit4]   2> 16719 T1725 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 16719 T1641 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:46420 which had sessionid 0x13a8162443f0009
[junit4:junit4]   2> 16719 T1639 oaz.ZooKeeper.close Session: 0x13a8162443f0009 closed
[junit4:junit4]   2> 16721 T1671 C212 P46368 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 16724 T1683 C214 P46375 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 16729 T1690 C211 P46381 REQ /select {fl=id,score&shard.url=127.0.0.1:46368/solr/collection1/|127.0.0.1:46381/solr/collection1/&NOW=1350790448520&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 16729 T1678 C214 P46375 REQ /select {fl=id,score&shard.url=127.0.0.1:46375/solr/collection1/|127.0.0.1:46388/solr/collection1/&NOW=1350790448520&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 16732 T1690 C211 P46381 REQ /select {shard.url=127.0.0.1:46368/solr/collection1/|127.0.0.1:46381/solr/collection1/&NOW=1350790448520&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16733 T1704 C213 P46388 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=7 
[junit4:junit4]   2> 16741 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[2 (1416406445358841856)]} 0 5
[junit4:junit4]   2> 16772 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=9 
[junit4:junit4]   2> 16773 T1682 C214 P46375 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=26 
[junit4:junit4]   2> 16774 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[2]} 0 30
[junit4:junit4]   2> 16779 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[3 (1416406445401833472)]} 0 2
[junit4:junit4]   2> 16789 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 16790 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[3 (1416406445406027776)]} 0 8
[junit4:junit4]   2> 16796 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[4 (1416406445418610688)]} 0 3
[junit4:junit4]   2> 16812 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 16813 T1669 C212 P46368 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=11 
[junit4:junit4]   2> 16814 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[4]} 0 14
[junit4:junit4]   2> 16819 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[5 (1416406445442727936)]} 0 2
[junit4:junit4]   2> 16829 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 16830 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[5 (1416406445449019392)]} 0 8
[junit4:junit4]   2> 16835 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[6 (1416406445460553728)]} 0 2
[junit4:junit4]   2> 16847 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 16848 T1682 C214 P46375 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 16848 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[6]} 0 10
[junit4:junit4]   2> 16853 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[7 (1416406445478379520)]} 0 2
[junit4:junit4]   2> 16861 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 16861 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[7 (1416406445483622400)]} 0 6
[junit4:junit4]   2> 16865 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[8 (1416406445492011008)]} 0 1
[junit4:junit4]   2> 16876 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16877 T1669 C212 P46368 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 16878 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[8]} 0 10
[junit4:junit4]   2> 16883 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[9 (1416406445510885376)]} 0 2
[junit4:junit4]   2> 16892 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 16892 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[9 (1416406445516128256)]} 0 6
[junit4:junit4]   2> 16897 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[10 (1416406445525565440)]} 0 2
[junit4:junit4]   2> 16908 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 16909 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[10 (1416406445530808320)]} 0 9
[junit4:junit4]   2> 16925 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[11 (1416406445543391232)]} 0 13
[junit4:junit4]   2> 16936 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16937 T1669 C212 P46368 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 16938 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[11]} 0 10
[junit4:junit4]   2> 16944 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[12 (1416406445572751360)]} 0 3
[junit4:junit4]   2> 16951 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16952 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[12 (1416406445577994240)]} 0 6
[junit4:junit4]   2> 16958 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[13 (1416406445588480000)]} 0 3
[junit4:junit4]   2> 16965 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16966 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[13 (1416406445593722880)]} 0 5
[junit4:junit4]   2> 16970 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[14 (1416406445602111488)]} 0 1
[junit4:junit4]   2> 16982 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 16983 T1669 C212 P46368 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 16984 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[14]} 0 11
[junit4:junit4]   2> 16989 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[15 (1416406445622034432)]} 0 2
[junit4:junit4]   2> 16996 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16997 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[15 (1416406445626228736)]} 0 5
[junit4:junit4]   2> 17000 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[16 (1416406445633568768)]} 0 1
[junit4:junit4]   2> 17011 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17012 T1669 C212 P46368 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 17012 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[16]} 0 9
[junit4:junit4]   2> 17019 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[17 (1416406445652443136)]} 0 3
[junit4:junit4]   2> 17035 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 17036 T1682 C214 P46375 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 17036 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[17]} 0 14
[junit4:junit4]   2> 17041 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[100 (1416406445676560384)]} 0 2
[junit4:junit4]   2> 17088 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=16 
[junit4:junit4]   2> 17089 T1669 C212 P46368 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=43 
[junit4:junit4]   2> 17090 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[100]} 0 47
[junit4:junit4]   2> 17095 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[101 (1416406445733183488)]} 0 2
[junit4:junit4]   2> 17108 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17109 T1669 C212 P46368 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=9 
[junit4:junit4]   2> 17110 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[101]} 0 13
[junit4:junit4]   2> 17115 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[102 (1416406445754155008)]} 0 2
[junit4:junit4]   2> 17123 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17124 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[102 (1416406445758349312)]} 0 6
[junit4:junit4]   2> 17140 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[103 (1416406445767786496)]} 0 13
[junit4:junit4]   2> 17149 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17150 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[103 (1416406445785612288)]} 0 7
[junit4:junit4]   2> 17156 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[104 (1416406445795049472)]} 0 3
[junit4:junit4]   2> 17166 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17167 T1682 C214 P46375 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 17168 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[104]} 0 9
[junit4:junit4]   2> 17171 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[105 (1416406445812875264)]} 0 1
[junit4:junit4]   2> 17205 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=17 
[junit4:junit4]   2> 17206 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[105 (1416406445817069568)]} 0 32
[junit4:junit4]   2> 17210 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[106 (1416406445853769728)]} 0 1
[junit4:junit4]   2> 17221 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 17222 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[106 (1416406445857964032)]} 0 9
[junit4:junit4]   2> 17225 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[107 (1416406445869498368)]} 0 1
[junit4:junit4]   2> 17232 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17233 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[107 (1416406445873692672)]} 0 5
[junit4:junit4]   2> 17237 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[108 (1416406445882081280)]} 0 1
[junit4:junit4]   2> 17244 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17245 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[108 (1416406445886275584)]} 0 5
[junit4:junit4]   2> 17249 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[109 (1416406445894664192)]} 0 1
[junit4:junit4]   2> 17258 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17258 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[109 (1416406445898858496)]} 0 6
[junit4:junit4]   2> 17262 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[110 (1416406445908295680)]} 0 1
[junit4:junit4]   2> 17270 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17270 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[110 (1416406445912489984)]} 0 5
[junit4:junit4]   2> 17274 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[111 (1416406445920878592)]} 0 1
[junit4:junit4]   2> 17285 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17286 T1669 C212 P46368 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 17286 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[111]} 0 9
[junit4:junit4]   2> 17290 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[112 (1416406445937655808)]} 0 1
[junit4:junit4]   2> 17298 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17299 T1682 C214 P46375 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 17300 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[112]} 0 8
[junit4:junit4]   2> 17312 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[113 (1416406445951287296)]} 0 10
[junit4:junit4]   2> 17324 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17324 T1669 C212 P46368 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 17325 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[113]} 0 10
[junit4:junit4]   2> 17330 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[114 (1416406445978550272)]} 0 2
[junit4:junit4]   2> 17342 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17343 T1669 C212 P46368 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 17343 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[114]} 0 10
[junit4:junit4]   2> 17347 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[115 (1416406445997424640)]} 0 1
[junit4:junit4]   2> 17355 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17355 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[115 (1416406446001618944)]} 0 5
[junit4:junit4]   2> 17359 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[116 (1416406446010007552)]} 0 1
[junit4:junit4]   2> 17368 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17369 T1682 C214 P46375 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 17370 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[116]} 0 8
[junit4:junit4]   2> 17374 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[117 (1416406446025736192)]} 0 1
[junit4:junit4]   2> 17381 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17382 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[117 (1416406446029930496)]} 0 5
[junit4:junit4]   2> 17386 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[118 (1416406446038319104)]} 0 1
[junit4:junit4]   2> 17419 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=14 
[junit4:junit4]   2> 17420 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[118 (1416406446042513408)]} 0 31
[junit4:junit4]   2> 17424 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[119 (1416406446078164992)]} 0 1
[junit4:junit4]   2> 17433 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17434 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[119 (1416406446083407872)]} 0 7
[junit4:junit4]   2> 17437 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[120 (1416406446091796480)]} 0 1
[junit4:junit4]   2> 17445 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17445 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[120 (1416406446095990784)]} 0 5
[junit4:junit4]   2> 17449 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[121 (1416406446104379392)]} 0 1
[junit4:junit4]   2> 17458 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17459 T1682 C214 P46375 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 17460 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[121]} 0 8
[junit4:junit4]   2> 17463 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[122 (1416406446119059456)]} 0 1
[junit4:junit4]   2> 17477 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 17478 T1669 C212 P46368 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 17479 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[122]} 0 13
[junit4:junit4]   2> 17495 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[123 (1416406446138982400)]} 0 14
[junit4:junit4]   2> 17504 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17505 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[123 (1416406446157856768)]} 0 7
[junit4:junit4]   2> 17510 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[124 (1416406446167293952)]} 0 2
[junit4:junit4]   2> 17519 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17520 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[124 (1416406446172536832)]} 0 7
[junit4:junit4]   2> 17524 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[125 (1416406446183022592)]} 0 1
[junit4:junit4]   2> 17535 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17536 T1669 C212 P46368 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 17536 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[125]} 0 9
[junit4:junit4]   2> 17540 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[126 (1416406446199799808)]} 0 1
[junit4:junit4]   2> 17547 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17548 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[126 (1416406446203994112)]} 0 5
[junit4:junit4]   2> 17552 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[127 (1416406446212382720)]} 0 1
[junit4:junit4]   2> 17584 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=13 
[junit4:junit4]   2> 17585 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[127 (1416406446216577024)]} 0 30
[junit4:junit4]   2> 17589 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[128 (1416406446251180032)]} 0 1
[junit4:junit4]   2> 17602 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 17603 T1682 C214 P46375 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 17603 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[128]} 0 11
[junit4:junit4]   2> 17607 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[129 (1416406446270054400)]} 0 1
[junit4:junit4]   2> 17616 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17616 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[129 (1416406446275297280)]} 0 6
[junit4:junit4]   2> 17621 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[130 (1416406446284734464)]} 0 1
[junit4:junit4]   2> 17632 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17633 T1682 C214 P46375 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 17633 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[130]} 0 9
[junit4:junit4]   2> 17637 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[131 (1416406446301511680)]} 0 1
[junit4:junit4]   2> 17648 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17648 T1682 C214 P46375 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 17649 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[131]} 0 9
[junit4:junit4]   2> 17653 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[132 (1416406446318288896)]} 0 1
[junit4:junit4]   2> 17662 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17663 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[132 (1416406446323531776)]} 0 7
[junit4:junit4]   2> 17674 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[133 (1416406446331920384)]} 0 9
[junit4:junit4]   2> 17683 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17684 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[133 (1416406446344503296)]} 0 7
[junit4:junit4]   2> 17688 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[134 (1416406446353940480)]} 0 2
[junit4:junit4]   2> 17697 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17698 T1682 C214 P46375 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 17699 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[134]} 0 8
[junit4:junit4]   2> 17702 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[135 (1416406446369669120)]} 0 1
[junit4:junit4]   2> 17713 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17713 T1669 C212 P46368 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 17714 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[135]} 0 9
[junit4:junit4]   2> 17718 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[136 (1416406446386446336)]} 0 1
[junit4:junit4]   2> 17728 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17729 T1682 C214 P46375 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 17730 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[136]} 0 9
[junit4:junit4]   2> 17733 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[137 (1416406446402174976)]} 0 1
[junit4:junit4]   2> 17743 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17744 T1682 C214 P46375 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 17745 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[137]} 0 9
[junit4:junit4]   2> 17749 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[138 (1416406446418952192)]} 0 1
[junit4:junit4]   2> 17758 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17758 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[138 (1416406446423146496)]} 0 6
[junit4:junit4]   2> 17762 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[139 (1416406446432583680)]} 0 1
[junit4:junit4]   2> 17769 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17770 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[139 (1416406446436777984)]} 0 5
[junit4:junit4]   2> 17774 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[140 (1416406446445166592)]} 0 1
[junit4:junit4]   2> 17783 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17784 T1682 C214 P46375 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 17785 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[140]} 0 8
[junit4:junit4]   2> 17788 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[141 (1416406446459846656)]} 0 1
[junit4:junit4]   2> 17794 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17795 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[141 (1416406446462992384)]} 0 5
[junit4:junit4]   2> 17799 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[142 (1416406446471380992)]} 0 1
[junit4:junit4]   2> 17824 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=12 
[junit4:junit4]   2> 17825 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[142 (1416406446475575296)]} 0 23
[junit4:junit4]   2> 17837 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[143 (1416406446502838272)]} 0 9
[junit4:junit4]   2> 17849 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17850 T1682 C214 P46375 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 17851 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[143]} 0 11
[junit4:junit4]   2> 17855 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[144 (1416406446529052672)]} 0 2
[junit4:junit4]   2> 17862 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17863 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[144 (1416406446534295552)]} 0 5
[junit4:junit4]   2> 17866 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[145 (1416406446541635584)]} 0 1
[junit4:junit4]   2> 17875 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17876 T1682 C214 P46375 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 17876 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[145]} 0 8
[junit4:junit4]   2> 17880 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[146 (1416406446556315648)]} 0 1
[junit4:junit4]   2> 17917 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=12 
[junit4:junit4]   2> 17918 T1669 C212 P46368 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=34 
[junit4:junit4]   2> 17919 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[146]} 0 36
[junit4:junit4]   2> 17923 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[147 (1416406446601404416)]} 0 1
[junit4:junit4]   2> 17930 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17931 T1679 C214 P46375 /update {wt=javabin&version=2} {add=[147 (1416406446605598720)]} 0 5
[junit4:junit4]   2> 17934 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[148 (1416406446612938752)]} 0 1
[junit4:junit4]   2> 17943 T1689 C211 P46381 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 17943 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[148 (1416406446616084480)]} 0 7
[junit4:junit4]   2> 17947 T1651 C215 P46361 /update {wt=javabin&version=2} {add=[149 (1416406446626570240)]} 0 1
[junit4:junit4]   2> 17961 T1703 C213 P46388 REQ /update {distrib.from=http://127.0.0.1:46375/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17962 T1682 C214 P46375 REQ /update {distrib.from=http://127.0.0.1:46368/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 17963 T1670 C212 P46368 /update {wt=javabin&version=2} {add=[149]} 0 7
[junit4:junit4]   2> 17963 T1639 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):1800
[junit4:junit4]   2> 17964 T1639 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 17967 T1651 C215 P46361 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 18460 T1651 C215 P46361 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2bfbe8ef; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Lucene41WithOrds_0.tib, _0_Asserting_0.tim, _0_Asserting_0.tip, _0_MockSep_0.pos, _0_Lucene41WithOrds_0.tii, _0_Lucene41WithOrds_0.pos, _0_MockSep_0.skp, _0.si, _0_MockSep_0.doc, _0_Asserting_0.doc, _0_MockRandom_0.tib, _0.fnm, _0_Lucene41WithOrds_0.doc, _0_nrm.cfs, _0_MockSep_0.tib, _0_MockRandom_0.sd, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0_nrm.cfe, segments_2, _0_MockSep_0.frq, _0_MockRandom_0.tii, _0.fdx, _0_MockSep_0.tii, _0_MockSep_0.pyl, _0_Asserting_0.pos, _0.fdt]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2bfbe8ef; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[_5_nrm.cfe, _2_Lucene41WithOrds_0.doc, _0_MockSep_0.pos, _2_Asserting_0.pos, _4_MockSep_0.tib, _4_MockSep_0.skp, _7.si, _3.fdt, _3_MockSep_0.frq, _1_MockRandom_0.pos, _2_MockSep_0.doc, _7.fnm, _1_Asserting_0.tim, _6_MockSep_0.doc, _1_Asserting_0.tip, _7_Lucene41WithOrds_0.pos, _5_MockSep_0.skp, _4_MockSep_0.doc, _6_MockSep_0.frq, _7_MockSep_0.tib, _5_Asserting_0.pos, _1_MockSep_0.pyl, _1_MockRandom_0.tiv, _1_MockSep_0.skp, _7_MockSep_0.tii, _5_Lucene41WithOrds_0.doc, _4_Lucene41WithOrds_0.pos, _4_Lucene41WithOrds_0.tii, _1_MockSep_0.tib, _2.fdt, _7.fdx, _1_MockRandom_0.sd, _5_MockSep_0.doc, _2.fdx, _7.fdt, _4_Lucene41WithOrds_0.tib, _1_MockSep_0.tii, _1.fdx, _2_Asserting_0.tim, _1_MockRandom_0.tib, _2_Asserting_0.tip, _7_MockSep_0.doc, _5_nrm.cfs, _4_MockSep_0.pyl, _1.fdt, _3_MockSep_0.pos, _1_Lucene41WithOrds_0.tii, _2_Lucene41WithOrds_0.pos, _1_Lucene41WithOrds_0.tib, _3.si, _1_MockRandom_0.doc, _6.fdt, _7_Asserting_0.pos, _4_MockSep_0.tii, _0_Lucene41WithOrds_0.tib, _0_Asserting_0.tim, _2.si, _0_Asserting_0.tip, _6_MockSep_0.pyl, _3_Lucene41WithOrds_0.doc, _6.fdx, _2_MockSep_0.skp, _0_Lucene41WithOrds_0.tii, _4_Asserting_0.tip, _0_Lucene41WithOrds_0.pos, _3.fnm, _5_MockSep_0.tii, _3_Asserting_0.pos, _2_MockRandom_0.tiv, _3_MockSep_0.pyl, _5_Asserting_0.doc, _4_Asserting_0.pos, _2_nrm.cfe, _7_MockSep_0.frq, _4_Asserting_0.tim, _2_Asserting_0.doc, _6_MockSep_0.pos, _4_Lucene41WithOrds_0.doc, _2_MockRandom_0.pyl, _2_MockRandom_0.tib, _2_nrm.cfs, _0_Lucene41WithOrds_0.doc, _2_Lucene41WithOrds_0.tii, _1_MockSep_0.pos, _2_Lucene41WithOrds_0.tib, _6_MockSep_0.skp, _2.fnm, _3.fdx, _2_MockRandom_0.sd, _2_MockSep_0.pyl, _2_MockRandom_0.skp, _5_MockSep_0.tib, _3_Asserting_0.doc, _1.si, _6.si, _6.fnm, _3_MockSep_0.skp, _0_Asserting_0.pos, _2_MockRandom_0.doc, _3_nrm.cfe, _3_MockSep_0.doc, _5_MockSep_0.pos, _5.fdt, _1_Lucene41WithOrds_0.doc, _4_nrm.cfe, _4.fnm, _1.fnm, _4.fdx, _0_MockSep_0.skp, _7_MockSep_0.skp, _3_MockSep_0.tib, _4_Asserting_0.doc, _7_Asserting_0.tip, _7_MockSep_0.pos, _0_Asserting_0.doc, _7_Asserting_0.tim, _6_MockSep_0.tii, _3_Lucene41WithOrds_0.pos, _1_MockSep_0.doc, _1_Asserting_0.pos, _6_MockSep_0.tib, _0.fnm, _7_Lucene41WithOrds_0.tii, _4_MockSep_0.pos, _5_Asserting_0.tim, _6_Asserting_0.doc, _5_MockSep_0.frq, _2_MockSep_0.tii, _2_MockSep_0.tib, _3_MockSep_0.tii, _5.si, _3_nrm.cfs, _0_MockRandom_0.doc, _4_nrm.cfs, _0_MockRandom_0.pos, _5_Asserting_0.tip, _2_MockSep_0.pos, _7_Lucene41WithOrds_0.doc, _7_Lucene41WithOrds_0.tib, _5_MockSep_0.pyl, _1_MockSep_0.frq, _5_Lucene41WithOrds_0.tib, _5_Lucene41WithOrds_0.tii, _6_Lucene41WithOrds_0.pos, _1_Asserting_0.doc, _1_Lucene41WithOrds_0.pos, _6_Asserting_0.tim, _6_Asserting_0.tip, _6_nrm.cfs, _7_nrm.cfs, _3_Lucene41WithOrds_0.tib, _7_MockSep_0.pyl, _2_MockRandom_0.pos, _0.si, _0_MockSep_0.doc, _3_Lucene41WithOrds_0.tii, _1_nrm.cfs, _0_MockRandom_0.tib, _5.fnm, _7_nrm.cfe, _6_nrm.cfe, _2_MockSep_0.frq, _4.si, _4.fdt, _0_nrm.cfs, _6_Lucene41WithOrds_0.tib, _1_nrm.cfe, _7_Asserting_0.doc, _0_MockSep_0.tib, _0_MockRandom_0.sd, _6_Asserting_0.pos, _5_Lucene41WithOrds_0.pos, _3_Asserting_0.tim, _6_Lucene41WithOrds_0.tii, _3_Asserting_0.tip, _6_Lucene41WithOrds_0.doc, _0_nrm.cfe, _5.fdx, _4_MockSep_0.frq, _0_MockSep_0.frq, _0_MockRandom_0.tii, _2_MockRandom_0.frq, _0.fdx, _0_MockSep_0.tii, _0_MockSep_0.pyl, _0.fdt, segments_3]
[junit4:junit4]   2> 18461 T1651 C215 P46361 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 18537 T1651 C215 P46361 oass.SolrIndexSearcher.<init> Opening Searcher@2c58dde3 main
[junit4:junit4]   2> 18538 T1651 C215 P46361 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18539 T1662 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2c58dde3 main{StandardDirectoryReader(segments_3:17 _0(5.0):C1 _1(5.0):C10 _2(5.0):C10 _3(5.0):C10 _4(5.0):C10 _5(5.0):C10 _6(5.0):C10 _7(5.0):C6)}
[junit4:junit4]   2> 18540 T1651 C215 P46361 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 573
[junit4:junit4]   2> 18542 T1679 C214 P46375 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 18883 T1679 C214 P46375 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@8c85d6b; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@8c85d6b; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_3_MockSep_0.doc, _3_nrm.cfe, _2_Lucene41WithOrds_0.doc, _2_Asserting_0.pos, _0_MockSep_0.pos, _1_Lucene41WithOrds_0.doc, _3.fdt, _3_MockSep_0.frq, _2_MockSep_0.doc, _1.fnm, _1_Asserting_0.tim, _0_MockSep_0.skp, _3_MockSep_0.tib, _1_Asserting_0.tip, _0_Asserting_0.doc, _3_Lucene41WithOrds_0.pos, _1_MockSep_0.doc, _1_MockSep_0.pyl, _1_Asserting_0.pos, _1_MockSep_0.skp, _0.fnm, _1_MockSep_0.tib, _2.fdt, _2_MockSep_0.tii, _3_MockSep_0.tii, _2_MockSep_0.tib, _2.fdx, _1_MockSep_0.tii, _3_nrm.cfs, _2_Asserting_0.tim, _1.fdx, _2_Asserting_0.tip, _3_MockSep_0.pos, _1.fdt, _0_MockRandom_0.doc, _2_Lucene41WithOrds_0.pos, _1_Lucene41WithOrds_0.tii, _0_MockRandom_0.pos, _1_Lucene41WithOrds_0.tib, _3.si, _2_MockSep_0.pos, _2.si, _0_Asserting_0.tim, _0_Lucene41WithOrds_0.tib, _1_MockSep_0.frq, _0_Asserting_0.tip, _3_Lucene41WithOrds_0.doc, _2_MockSep_0.skp, _1_Asserting_0.doc, _0_Lucene41WithOrds_0.tii, _1_Lucene41WithOrds_0.pos, _0_Lucene41WithOrds_0.pos, _3.fnm, _3_Asserting_0.pos, _3_MockSep_0.pyl, _2_nrm.cfe, _3_Lucene41WithOrds_0.tib, _2_Asserting_0.doc, _2_nrm.cfs, _0_MockSep_0.doc, _0.si, _3_Lucene41WithOrds_0.tii, _1_nrm.cfs, _2_Lucene41WithOrds_0.tii, _0_Lucene41WithOrds_0.doc, _1_MockSep_0.pos, _2_MockSep_0.frq, _2_Lucene41WithOrds_0.tib, _0_nrm.cfs, _2.fnm, _1_nrm.cfe, _3.fdx, _0_MockSep_0.tib, _0_MockRandom_0.tip, _0_MockRandom_0.sd, _2_MockSep_0.pyl, _3_Asserting_0.tim, _3_Asserting_0.tip, _3_Asserting_0.doc, _1.si, _0_nrm.cfe, _0_MockSep_0.frq, segments_2, _0.fdx, _3_MockSep_0.skp, _0_MockSep_0.tii, _0_Asserting_0.pos, _0_MockSep_0.pyl, _0_MockRandom_0.tim, _0.fdt]
[junit4:junit4]   2> 18884 T1679 C214 P46375 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 18891 T1679 C214 P46375 oass.SolrIndexSearcher.<init> Opening Searcher@4a562c66 main
[junit4:junit4]   2> 18892 T1679 C214 P46375 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18893 T1686 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4a562c66 main{StandardDirectoryReader(segments_2:9:nrt _0(5.0):C10 _1(5.0):C10 _2(5.0):C10 _3(5.0):C5)}
[junit4:junit4]   2> 18894 T1679 C214 P46375 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:46368/solr/collection1/, StdNode: http://127.0.0.1:46381/solr/collection1/, StdNode: http://127.0.0.1:46388/solr/collection1/]
[junit4:junit4]   2> 18897 T1703 C213 P46388 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 18897 T1669 C212 P46368 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 18897 T1689 C211 P46381 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 19383 T1689 C211 P46381 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2aa21f25; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[_0_Lucene41WithOrds_0.tib, _0_Asserting_0.tim, _0_Asserting_0.tip, _0_MockSep_0.pos, _0_Lucene41WithOrds_0.tii, _0_Lucene41WithOrds_0.pos, _0_MockSep_0.skp, _0.si, _0_MockSep_0.doc, _0_Asserting_0.doc, _0_MockRandom_0.tib, _0.fnm, _0_Lucene41WithOrds_0.doc, _0_nrm.cfs, _0_MockSep_0.tib, _0_MockRandom_0.sd, _0_MockRandom_0.tiv, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0_nrm.cfe, _0_MockSep_0.frq, _0.fdx, _0_MockSep_0.tii, _0_MockSep_0.pyl, _0_Asserting_0.pos, _0.fdt, segments_3]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2aa21f25; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_4,generation=4,filenames=[_2_Lucene41WithOrds_0.doc, _0_MockSep_0.pos, _2_Asserting_0.pos, _4_MockSep_0.tib, _4_MockSep_0.skp, _3.fdt, _3_MockSep_0.frq, _1_MockRandom_0.pos, _2_MockSep_0.doc, _1_Asserting_0.tim, _1_Asserting_0.tip, _4_MockSep_0.doc, _1_MockSep_0.pyl, _1_MockSep_0.skp, _4_Lucene41WithOrds_0.pos, _4_Lucene41WithOrds_0.tii, _1_MockSep_0.tib, _2.fdt, _1_MockRandom_0.sd, _2.fdx, _1_MockRandom_0.tii, _4_Lucene41WithOrds_0.tib, _1_MockSep_0.tii, _1.fdx, _2_Asserting_0.tim, _1_MockRandom_0.tib, _2_Asserting_0.tip, _4_MockSep_0.pyl, _1.fdt, _3_MockSep_0.pos, _1_Lucene41WithOrds_0.tii, _2_Lucene41WithOrds_0.pos, _1_Lucene41WithOrds_0.tib, _1_MockRandom_0.doc, _3.si, _4_MockSep_0.tii, _0_Lucene41WithOrds_0.tib, _0_Asserting_0.tim, _2.si, _0_Asserting_0.tip, _3_Lucene41WithOrds_0.doc, _2_MockSep_0.skp, _0_Lucene41WithOrds_0.tii, _4_Asserting_0.tip, _0_Lucene41WithOrds_0.pos, _3.fnm, _3_Asserting_0.pos, _3_MockSep_0.pyl, _4_Asserting_0.pos, _2_nrm.cfe, _4_Asserting_0.tim, _2_Asserting_0.doc, _4_Lucene41WithOrds_0.doc, _2_nrm.cfs, _0_Lucene41WithOrds_0.doc, _2_Lucene41WithOrds_0.tii, _1_MockSep_0.pos, _2_Lucene41WithOrds_0.tib, _2.fnm, _3.fdx, _2_MockSep_0.pyl, _1.si, _3_Asserting_0.doc, _3_MockSep_0.skp, _0_Asserting_0.pos, _3_nrm.cfe, _3_MockSep_0.doc, _1_Lucene41WithOrds_0.doc, _4_nrm.cfe, _4.fnm, _1.fnm, _4.fdx, _0_MockSep_0.skp, _3_MockSep_0.tib, _4_Asserting_0.doc, _0_Asserting_0.doc, _3_Lucene41WithOrds_0.pos, _1_MockSep_0.doc, _1_Asserting_0.pos, _0.fnm, _4_MockSep_0.pos, _2_MockSep_0.tii, _2_MockSep_0.tib, _3_MockSep_0.tii, _3_nrm.cfs, _0_MockRandom_0.doc, _4_nrm.cfs, _0_MockRandom_0.pos, _2_MockSep_0.pos, _1_MockSep_0.frq, _1_Asserting_0.doc, _1_Lucene41WithOrds_0.pos, _3_Lucene41WithOrds_0.tib, _0.si, _0_MockSep_0.doc, _3_Lucene41WithOrds_0.tii, _1_nrm.cfs, _0_MockRandom_0.tib, _2_MockSep_0.frq, _4.si, _4.fdt, _0_nrm.cfs, _1_nrm.cfe, _0_MockSep_0.tib, _0_MockRandom_0.sd, _0_MockRandom_0.tiv, _3_Asserting_0.tim, _3_Asserting_0.tip, _0_nrm.cfe, _4_MockSep_0.frq, _0_MockSep_0.frq, _0.fdx, _0_MockSep_0.tii, _0_MockSep_0.pyl, _0.fdt, segments_4]
[junit4:junit4]   2> 19384 T1689 C211 P46381 oasc.SolrDeletionPolicy.updateCommits newest commit = 4
[junit4:junit4]   2> 19414 T1703 C213 P46388 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@3909c794; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1350790431799/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@3909c794; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[_3_MockSep_0.doc, _3_nrm.cfe, _2_Lucene41WithOrds_0.doc, _2_Asserting_0.pos, _0_MockSep_0.pos, _1_Lucene41WithOrds_0.doc, _3.fdt, _3_MockSep_0.frq, _2_MockSep_0.doc, _1.fnm, _1_Asserting_0.tim, _0_MockSep_0.skp, _3_MockSep_0.tib, _1_Asserting_0.tip, _0_Asserting_0.doc, _3_Lucene41WithOrds_0.pos, _1_MockSep_0.doc, _1_MockSep_0.pyl, _1_Asserting_0.pos, _1_MockSep_0.skp, _0.fnm, _1_MockSep_0.tib, _2.fdt, _2_MockSep_0.tii, _3_MockSep_0.tii, _2_MockSep_0.tib, _2.fdx, _1_MockSep_0.tii, _3_nrm.cfs, _2_Asserting_0.tim, _1.fdx, _2_Asserting_0.tip, _3_MockSep_0.pos, _1.fdt, _0_MockRandom_0.doc, _2_Luce

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

r$ConnectorEndPoint.fill(SocketConnector.java:222)
[junit4:junit4]   2> 	        at org.eclipse.jetty.http.HttpParser.fill(HttpParser.java:1038)
[junit4:junit4]   2> 	        at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:276)
[junit4:junit4]   2> 	        at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:230)
[junit4:junit4]   2> 	        at org.eclipse.jetty.server.BlockingHttpConnection.handle(BlockingHttpConnection.java:66)
[junit4:junit4]   2> 	        at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.run(SocketConnector.java:254)
[junit4:junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:599)
[junit4:junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:534)
[junit4:junit4]   2> 	        at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 	  33) Thread[id=1674, name=searcherExecutor-1411-thread-1, state=WAITING, group=TGRP-BasicDistributedZk2Test]
[junit4:junit4]   2> 	        at sun.misc.Unsafe.park(Native Method)
[junit4:junit4]   2> 	        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
[junit4:junit4]   2> 	        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
[junit4:junit4]   2> 	        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
[junit4:junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1043)
[junit4:junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1103)
[junit4:junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
[junit4:junit4]   2> 	        at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 	  34) Thread[id=1702, name=qtp1340827041-1702 Acceptor0 SocketConnector@0.0.0.0:46388, state=RUNNABLE, group=TGRP-BasicDistributedZk2Test]
[junit4:junit4]   2> 	        at java.net.PlainSocketImpl.socketAccept(Native Method)
[junit4:junit4]   2> 	        at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398)
[junit4:junit4]   2> 	        at java.net.ServerSocket.implAccept(ServerSocket.java:522)
[junit4:junit4]   2> 	        at java.net.ServerSocket.accept(ServerSocket.java:490)
[junit4:junit4]   2> 	        at org.eclipse.jetty.server.bio.SocketConnector.accept(SocketConnector.java:112)
[junit4:junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:933)
[junit4:junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:599)
[junit4:junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:534)
[junit4:junit4]   2> 	        at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 	  35) Thread[id=1708, name=qtp1340827041-1708, state=RUNNABLE, group=TGRP-BasicDistributedZk2Test]
[junit4:junit4]   2> 	        at java.net.SocketInputStream.socketRead0(Native Method)
[junit4:junit4]   2> 	        at java.net.SocketInputStream.read(SocketInputStream.java:150)
[junit4:junit4]   2> 	        at java.net.SocketInputStream.read(SocketInputStream.java:121)
[junit4:junit4]   2> 	        at org.eclipse.jetty.io.ByteArrayBuffer.readFrom(ByteArrayBuffer.java:369)
[junit4:junit4]   2> 	        at org.eclipse.jetty.io.bio.StreamEndPoint.fill(StreamEndPoint.java:136)
[junit4:junit4]   2> 	        at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.fill(SocketConnector.java:222)
[junit4:junit4]   2> 	        at org.eclipse.jetty.http.HttpParser.fill(HttpParser.java:1038)
[junit4:junit4]   2> 	        at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:276)
[junit4:junit4]   2> 	        at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:230)
[junit4:junit4]   2> 	        at org.eclipse.jetty.server.BlockingHttpConnection.handle(BlockingHttpConnection.java:66)
[junit4:junit4]   2> 	        at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.run(SocketConnector.java:254)
[junit4:junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:599)
[junit4:junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:534)
[junit4:junit4]   2> 	        at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> NOTE: test params are: codec=Lucene41: {n_f1=PostingsFormat(name=MockSep), foo_b=PostingsFormat(name=MockRandom), foo_d=PostingsFormat(name=Lucene41WithOrds), foo_f=PostingsFormat(name=MockRandom), n_tl1=PostingsFormat(name=MockSep), n_d1=PostingsFormat(name=Asserting), rnd_b=PostingsFormat(name=Lucene41WithOrds), intDefault=PostingsFormat(name=MockSep), n_td1=PostingsFormat(name=MockSep), timestamp=PostingsFormat(name=Asserting), id=PostingsFormat(name=Lucene41WithOrds), range_facet_sl=PostingsFormat(name=Lucene41WithOrds), range_facet_si=PostingsFormat(name=Asserting), oddField_s=PostingsFormat(name=Lucene41WithOrds), multiDefault=PostingsFormat(name=Asserting), n_tf1=PostingsFormat(name=Asserting), n_dt1=PostingsFormat(name=MockSep), n_ti1=PostingsFormat(name=Lucene41WithOrds), range_facet_l=PostingsFormat(name=Asserting), text=PostingsFormat(name=MockRandom), _version_=PostingsFormat(name=MockSep), SubjectTerms_mfacet=PostingsFormat(name=MockSep), a_t=PostingsFormat(name=Asserting), n_tdt1=PostingsFormat(name=MockSep), other_tl1=PostingsFormat(name=MockSep), n_l1=PostingsFormat(name=Asserting), a_si=PostingsFormat(name=MockSep)}, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=es_HN, timezone=Etc/GMT0
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Oracle Corporation 1.7.0_06 (64-bit)/cpus=16,threads=46,free=218551128,total=457179136
[junit4:junit4]   2> NOTE: All tests run in this JVM: [SOLR749Test, DateMathParserTest, TestRangeQuery, TestBinaryResponseWriter, SpellCheckComponentTest, TestLMDirichletSimilarityFactory, TestCollationField, TestCoreContainer, TestReload, SolrCoreCheckLockOnStartupTest, TestStressRecovery, ZkControllerTest, SimplePostToolTest, CopyFieldTest, DistributedTermsComponentTest, JSONWriterTest, FileBasedSpellCheckerTest, TestGroupingSearch, SpellPossibilityIteratorTest, SimpleFacetsTest, TestNumberUtils, UpdateRequestProcessorFactoryTest, TestIBSimilarityFactory, TermsComponentTest, IndexBasedSpellCheckerTest, TestPseudoReturnFields, NotRequiredUniqueKeyTest, MBeansHandlerTest, TestBadConfig, BadComponentTest, SampleTest, TestRTGBase, WordBreakSolrSpellCheckerTest, SpatialFilterTest, DistributedSpellCheckComponentTest, TestDefaultSimilarityFactory, RequestHandlersTest, CurrencyFieldTest, TestPHPSerializedResponseWriter, TestSolrQueryParser, JsonLoaderTest, CSVRequestHandlerTest, SuggesterFSTTest, LoggingHandlerTest, SyncSliceTest, TestStressLucene, SpellCheckCollatorTest, TestFastLRUCache, DistanceFunctionTest, TestJmxMonitoredMap, SuggesterWFSTTest, NoCacheHeaderTest, BasicDistributedZkTest, TestExtendedDismaxParser, SoftAutoCommitTest, AutoCommitTest, BasicZkTest, TestHashPartitioner, TestMultiCoreConfBootstrap, LukeRequestHandlerTest, DirectSolrSpellCheckerTest, TestFiltering, ConvertedLegacyTest, QueryElevationComponentTest, SortByFunctionTest, BasicFunctionalityTest, HighlighterTest, TestIndexSearcher, TestTrie, DirectSolrConnectionTest, CacheHeaderTest, TestCSVLoader, DistributedQueryElevationComponentTest, SolrInfoMBeanTest, MinimalSchemaTest, XmlUpdateRequestHandlerTest, PingRequestHandlerTest, DocumentAnalysisRequestHandlerTest, IndexSchemaRuntimeFieldTest, FastVectorHighlighterTest, DebugComponentTest, SearchHandlerTest, TestOmitPositions, SolrCmdDistributorTest, TestLuceneMatchVersion, TestWriterPerf, AlternateDirectoryTest, TestBinaryField, DefaultValueUpdateProcessorTest, TestXIncludeConfig, TestLFUCache, TestQuerySenderNoQuery, NumericFieldsTest, TestConfig, TestBM25SimilarityFactory, TestPluginEnable, TimeZoneUtilsTest, URLClassifyProcessorTest, ResourceLoaderTest, TestSystemIdResolver, SpellingQueryConverterTest, UUIDFieldTest, PreAnalyzedFieldTest, CircularListTest, TestDocumentBuilder, TestCharFilters, BasicDistributedZk2Test]
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZk2Test -Dtests.seed=D1ACC6FED0C1015 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_HN -Dtests.timezone=Etc/GMT0 -Dtests.file.encoding=US-ASCII
[junit4:junit4] ERROR   0.00s J0 | BasicDistributedZk2Test (suite) <<<
[junit4:junit4]    > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([D1ACC6FED0C1015]:0)
[junit4:junit4] Completed on J0 in 7223.76s, 1 test, 2 errors <<< FAILURES!

[...truncated 12 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/build.xml:335: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build.xml:178: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/lucene/module-build.xml:61: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/lucene/common-build.xml:1170: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/lucene/common-build.xml:838: There were test failures: 231 suites, 958 tests, 1 suite-level error, 1 error, 21 ignored (3 assumptions)

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



Mime
View raw message