lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-Tests-4.x-java7 - Build # 444 - Failure
Date Fri, 14 Sep 2012 11:53:44 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-java7/444/

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([2EAC51F26CD7A0FB]: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([2EAC51F26CD7A0FB]:0)




Build Log:
[...truncated 8410 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 3 T1813 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1347616247849
[junit4:junit4]   2> 5 T1813 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 8 T1814 oazs.ZooKeeperServer.setTickTime tickTime set to 3000
[junit4:junit4]   2> 9 T1814 oazs.NIOServerCnxn$Factory.<init> binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 10 T1814 oazsp.FileTxnSnapLog.save Snapshotting: 0
[junit4:junit4]   2> 106 T1813 oasc.ZkTestServer.run start zk server on port:38313
[junit4:junit4]   2> 106 T1813 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:38313 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@3dba0bf5
[junit4:junit4]   2> 107 T1819 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:38313
[junit4:junit4]   2> 107 T1813 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 108 T1819 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:38313, initiating session
[junit4:junit4]   2> 109 T1815 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:38314
[junit4:junit4]   2> 109 T1815 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:38314
[junit4:junit4]   2> 109 T1817 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 112 T1817 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c430102f0000 with negotiated timeout 10000 for client /140.211.11.196:38314
[junit4:junit4]   2> 112 T1819 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:38313, sessionid = 0x139c430102f0000, negotiated timeout = 10000
[junit4:junit4]   2> 112 T1820 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3dba0bf5 name:ZooKeeperConnection Watcher:127.0.0.1:38313 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 112 T1813 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 113 T1813 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 124 T1818 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139c430102f0000
[junit4:junit4]   2> 126 T1820 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 126 T1815 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:38314 which had sessionid 0x139c430102f0000
[junit4:junit4]   2> 126 T1813 oaz.ZooKeeper.close Session: 0x139c430102f0000 closed
[junit4:junit4]   2> 127 T1813 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:38313/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@3d6c78fc
[junit4:junit4]   2> 128 T1821 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:38313
[junit4:junit4]   2> 128 T1813 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 128 T1821 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:38313, initiating session
[junit4:junit4]   2> 128 T1815 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:38315
[junit4:junit4]   2> 129 T1815 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:38315
[junit4:junit4]   2> 130 T1817 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c430102f0001 with negotiated timeout 10000 for client /140.211.11.196:38315
[junit4:junit4]   2> 131 T1821 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:38313, sessionid = 0x139c430102f0001, negotiated timeout = 10000
[junit4:junit4]   2> 131 T1822 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3d6c78fc name:ZooKeeperConnection Watcher:127.0.0.1:38313/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 131 T1813 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 131 T1813 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 140 T1813 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 143 T1813 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 145 T1813 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 153 T1813 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 154 T1813 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 165 T1813 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 166 T1813 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 270 T1813 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 271 T1813 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 274 T1813 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 275 T1813 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 285 T1813 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 286 T1813 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 289 T1813 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 289 T1813 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 292 T1813 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 293 T1813 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 296 T1813 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 296 T1813 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 303 T1813 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 304 T1813 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 307 T1813 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 307 T1813 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 310 T1818 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139c430102f0001
[junit4:junit4]   2> 316 T1822 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 317 T1815 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:38315 which had sessionid 0x139c430102f0001
[junit4:junit4]   2> 316 T1813 oaz.ZooKeeper.close Session: 0x139c430102f0001 closed
[junit4:junit4]   2> 320 T1813 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 325 T1813 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:38316
[junit4:junit4]   2> 326 T1813 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 327 T1813 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 327 T1813 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 370 T1813 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 371 T1813 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 371 T1813 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 372 T1813 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 372 T1813 oasc.CoreContainer.<init> New CoreContainer 1960181791
[junit4:junit4]   2> 373 T1813 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 373 T1813 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 407 T1813 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 423 T1813 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:38313/solr
[junit4:junit4]   2> 424 T1813 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:38313/solr sessionTimeout=8000 watcher=org.apache.solr.common.cloud.ConnectionManager@551706da
[junit4:junit4]   2> 425 T1832 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:38313
[junit4:junit4]   2> 425 T1813 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 427 T1832 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:38313, initiating session
[junit4:junit4]   2> 427 T1815 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:38317
[junit4:junit4]   2> 427 T1815 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:38317
[junit4:junit4]   2> 429 T1817 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c430102f0002 with negotiated timeout 8000 for client /140.211.11.196:38317
[junit4:junit4]   2> 429 T1832 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:38313, sessionid = 0x139c430102f0002, negotiated timeout = 8000
[junit4:junit4]   2> 429 T1833 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@551706da name:ZooKeeperConnection Watcher:127.0.0.1:38313/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 430 T1813 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 432 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0002 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 440 T1813 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 443 T1813 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38316_solr
[junit4:junit4]   2> 443 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0002 type:delete cxid:0x7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:38316_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:38316_solr
[junit4:junit4]   2> 446 T1813 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38316_solr
[junit4:junit4]   2> 449 T1813 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 449 T1813 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 450 T1813 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 450 T1813 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 451 T1813 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 451 T1813 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 452 T1813 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 452 T1813 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 453 T1813 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 453 T1813 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 468 T1813 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 476 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0002 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> 482 T1813 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 485 T1813 oasc.Overseer.start Overseer (id=88317378419425282-127.0.0.1:38316_solr-n_0000000000) starting
[junit4:junit4]   2> 485 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0002 type:create cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 487 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0002 type:create cxid:0x1b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 495 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0002 type:create cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 497 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0002 type:create cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 498 T1835 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 499 T1813 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 506 T1813 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 508 T1834 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 513 T1813 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 513 T1813 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 514 T1813 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 514 T1813 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 516 T1813 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 517 T1813 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 518 T1813 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 576 T1813 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 652 T1813 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 753 T1813 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 762 T1813 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1453 T1813 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1462 T1813 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1465 T1813 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1476 T1813 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1480 T1813 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1483 T1813 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1485 T1813 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1486 T1813 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/control/data/
[junit4:junit4]   2> 1486 T1813 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@10e61c47
[junit4:junit4]   2> 1487 T1813 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/control/data/index/
[junit4:junit4]   2> 1488 T1813 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1489 T1813 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/control/data/index forceNew:false
[junit4:junit4]   2> 1494 T1813 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@32b6e245; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1494 T1813 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 1495 T1813 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 1497 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1498 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 1498 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1498 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 1499 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1499 T1813 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1500 T1813 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1500 T1813 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1501 T1813 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1501 T1813 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 1502 T1813 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 1503 T1813 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1503 T1813 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 1503 T1813 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 1504 T1813 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 1504 T1813 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1505 T1813 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1505 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1506 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1506 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1507 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1507 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1508 T1813 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1508 T1813 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 1509 T1813 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 1511 T1813 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1515 T1813 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 1516 T1813 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> 1519 T1813 oass.SolrIndexSearcher.<init> Opening Searcher@53a11825 main
[junit4:junit4]   2> 1520 T1813 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1520 T1813 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1521 T1813 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 1534 T1813 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 1593 T1836 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@53a11825 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1597 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0002 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> 1609 T1813 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 1610 T1813 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:38316/solr shardId:control_shard
[junit4:junit4]   2> 1610 T1813 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/control_shard/election
[junit4:junit4]   2> 1629 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0002 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> 1630 T1813 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process. afterExpiration=false
[junit4:junit4]   2> 1631 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0002 type:create cxid:0x66 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1633 T1813 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:38316/solr/collection1/
[junit4:junit4]   2> 1633 T1813 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/control_shard
[junit4:junit4]   2> 1647 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0002 type:create cxid:0x6f zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2014 T1834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2015 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0002 type:create cxid:0x77 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 2033 T1833 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2063 T1813 oasc.ZkController.register We are http://127.0.0.1:38316/solr/collection1/ and leader is http://127.0.0.1:38316/solr/collection1/
[junit4:junit4]   2> 2063 T1813 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38316/solr
[junit4:junit4]   2> 2064 T1813 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 2065 T1813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2066 T1813 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0
[junit4:junit4]   2> 2066 T1813 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 2067 T1813 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2078 T1813 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 2080 T1813 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:38332
[junit4:junit4]   2> 2080 T1813 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2080 T1813 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 2081 T1813 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 2112 T1813 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 2113 T1813 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2113 T1813 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 2113 T1813 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 2114 T1813 oasc.CoreContainer.<init> New CoreContainer 318184474
[junit4:junit4]   2> 2114 T1813 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 2115 T1813 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 2142 T1813 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 2154 T1813 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:38313/solr
[junit4:junit4]   2> 2155 T1813 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:38313/solr sessionTimeout=8000 watcher=org.apache.solr.common.cloud.ConnectionManager@327021df
[junit4:junit4]   2> 2156 T1846 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:38313
[junit4:junit4]   2> 2156 T1813 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2157 T1846 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:38313, initiating session
[junit4:junit4]   2> 2157 T1815 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:38335
[junit4:junit4]   2> 2157 T1815 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:38335
[junit4:junit4]   2> 2159 T1817 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c430102f0003 with negotiated timeout 8000 for client /140.211.11.196:38335
[junit4:junit4]   2> 2159 T1846 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:38313, sessionid = 0x139c430102f0003, negotiated timeout = 8000
[junit4:junit4]   2> 2159 T1847 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@327021df name:ZooKeeperConnection Watcher:127.0.0.1:38313/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2159 T1813 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2160 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0003 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2161 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0003 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2169 T1813 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38332_solr
[junit4:junit4]   2> 2170 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0003 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:38332_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:38332_solr
[junit4:junit4]   2> 2171 T1813 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38332_solr
[junit4:junit4]   2> 2173 T1833 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 2174 T1813 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 2174 T1813 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 2174 T1813 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 2175 T1813 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 2175 T1813 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 2176 T1813 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 2176 T1813 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 2176 T1813 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 2177 T1813 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 2177 T1813 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 2185 T1813 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 2190 T1813 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 2191 T1813 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 2191 T1813 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 2192 T1813 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 2193 T1813 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 2194 T1813 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 2194 T1813 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 2233 T1813 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 2287 T1813 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 2388 T1813 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 2398 T1813 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 2539 T1834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2551 T1833 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2551 T1847 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3104 T1813 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 3116 T1813 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 3121 T1813 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 3134 T1813 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 3140 T1813 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 3145 T1813 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 3146 T1813 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 3147 T1813 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty1/
[junit4:junit4]   2> 3148 T1813 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@10e61c47
[junit4:junit4]   2> 3150 T1813 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty1/index/
[junit4:junit4]   2> 3151 T1813 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 3152 T1813 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty1/index forceNew:false
[junit4:junit4]   2> 3158 T1813 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2a63471c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 3159 T1813 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 3160 T1813 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 3163 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 3163 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 3164 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 3165 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 3166 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 3166 T1813 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 3167 T1813 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 3168 T1813 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 3168 T1813 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 3169 T1813 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 3170 T1813 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 3171 T1813 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 3172 T1813 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 3172 T1813 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 3173 T1813 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 3174 T1813 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 3175 T1813 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3175 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3176 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3177 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3178 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3179 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3180 T1813 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3180 T1813 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 3181 T1813 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 3185 T1813 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 3191 T1813 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 3192 T1813 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> 3197 T1813 oass.SolrIndexSearcher.<init> Opening Searcher@34260f88 main
[junit4:junit4]   2> 3198 T1813 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 3198 T1813 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 3199 T1813 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 3217 T1813 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 3275 T1848 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@34260f88 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 3558 T1834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3562 T1833 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3562 T1847 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3783 T1813 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 3783 T1813 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:38332/solr shardId:shard1
[junit4:junit4]   2> 3784 T1813 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 3799 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0003 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> 3800 T1813 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process. afterExpiration=false
[junit4:junit4]   2> 3801 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0003 type:create cxid:0x44 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3802 T1813 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:38332/solr/collection1/
[junit4:junit4]   2> 3802 T1813 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 3806 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0003 type:create cxid:0x4d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4065 T1834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4071 T1847 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4071 T1833 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4113 T1813 oasc.ZkController.register We are http://127.0.0.1:38332/solr/collection1/ and leader is http://127.0.0.1:38332/solr/collection1/
[junit4:junit4]   2> 4114 T1813 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38332/solr
[junit4:junit4]   2> 4114 T1813 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 4146 T1813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4148 T1813 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0
[junit4:junit4]   2> 4148 T1813 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 4148 T1813 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 4158 T1813 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 4161 T1813 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:38342
[junit4:junit4]   2> 4162 T1813 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4162 T1813 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 4162 T1813 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 4192 T1813 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 4193 T1813 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4193 T1813 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 4193 T1813 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 4194 T1813 oasc.CoreContainer.<init> New CoreContainer 874825320
[junit4:junit4]   2> 4194 T1813 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 4195 T1813 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 4218 T1813 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 4231 T1813 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:38313/solr
[junit4:junit4]   2> 4232 T1813 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:38313/solr sessionTimeout=8000 watcher=org.apache.solr.common.cloud.ConnectionManager@11ba381d
[junit4:junit4]   2> 4233 T1858 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:38313
[junit4:junit4]   2> 4233 T1813 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4234 T1858 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:38313, initiating session
[junit4:junit4]   2> 4234 T1815 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:38343
[junit4:junit4]   2> 4234 T1815 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:38343
[junit4:junit4]   2> 4251 T1817 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c430102f0004 with negotiated timeout 8000 for client /140.211.11.196:38343
[junit4:junit4]   2> 4251 T1858 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:38313, sessionid = 0x139c430102f0004, negotiated timeout = 8000
[junit4:junit4]   2> 4252 T1859 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11ba381d name:ZooKeeperConnection Watcher:127.0.0.1:38313/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4252 T1813 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4253 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0004 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4277 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0004 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4279 T1813 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38342_solr
[junit4:junit4]   2> 4280 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0004 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:38342_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:38342_solr
[junit4:junit4]   2> 4282 T1813 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38342_solr
[junit4:junit4]   2> 4315 T1847 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 4315 T1833 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 4315 T1813 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 4316 T1813 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 4317 T1813 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 4317 T1813 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 4317 T1813 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 4318 T1813 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 4318 T1813 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 4318 T1813 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 4319 T1813 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 4319 T1813 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 4327 T1813 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4332 T1813 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 4333 T1813 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 4333 T1813 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 4334 T1813 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 4335 T1813 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 4336 T1813 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 4336 T1813 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 4375 T1813 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 4448 T1813 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 4549 T1813 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 4559 T1813 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 4576 T1834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4593 T1847 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4593 T1859 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4593 T1833 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5241 T1813 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 5253 T1813 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 5258 T1813 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 5271 T1813 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5276 T1813 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5281 T1813 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5282 T1813 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5283 T1813 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty2/
[junit4:junit4]   2> 5284 T1813 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@10e61c47
[junit4:junit4]   2> 5285 T1813 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty2/index/
[junit4:junit4]   2> 5287 T1813 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 5288 T1813 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty2/index forceNew:false
[junit4:junit4]   2> 5294 T1813 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@67df730e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 5295 T1813 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 5296 T1813 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 5299 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 5299 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 5300 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 5301 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 5302 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 5302 T1813 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 5303 T1813 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 5304 T1813 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 5305 T1813 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 5305 T1813 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 5306 T1813 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 5307 T1813 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 5308 T1813 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 5308 T1813 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 5309 T1813 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 5310 T1813 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 5311 T1813 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5311 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5312 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5313 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5314 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5314 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5315 T1813 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5316 T1813 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 5317 T1813 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 5321 T1813 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 5326 T1813 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 5327 T1813 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> 5331 T1813 oass.SolrIndexSearcher.<init> Opening Searcher@da87d2f main
[junit4:junit4]   2> 5333 T1813 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 5333 T1813 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 5334 T1813 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 5342 T1813 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 5394 T1860 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@da87d2f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 5619 T1834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5632 T1847 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5632 T1859 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5632 T1833 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5902 T1813 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 5902 T1813 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:38342/solr shardId:shard2
[junit4:junit4]   2> 5903 T1813 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 5918 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0004 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> 5919 T1813 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process. afterExpiration=false
[junit4:junit4]   2> 5920 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0004 type:create cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5921 T1813 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:38342/solr/collection1/
[junit4:junit4]   2> 5922 T1813 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 5925 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0004 type:create cxid:0x4b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6135 T1834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6159 T1859 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6159 T1833 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6159 T1847 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6181 T1813 oasc.ZkController.register We are http://127.0.0.1:38342/solr/collection1/ and leader is http://127.0.0.1:38342/solr/collection1/
[junit4:junit4]   2> 6181 T1813 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38342/solr
[junit4:junit4]   2> 6182 T1813 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 6186 T1813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6187 T1813 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0
[junit4:junit4]   2> 6188 T1813 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 6188 T1813 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 6207 T1813 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 6210 T1813 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:38347
[junit4:junit4]   2> 6211 T1813 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 6211 T1813 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 6212 T1813 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 6262 T1813 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 6262 T1813 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 6263 T1813 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 6263 T1813 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 6264 T1813 oasc.CoreContainer.<init> New CoreContainer 1911352827
[junit4:junit4]   2> 6265 T1813 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 6265 T1813 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 6303 T1813 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 6321 T1813 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:38313/solr
[junit4:junit4]   2> 6322 T1813 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:38313/solr sessionTimeout=8000 watcher=org.apache.solr.common.cloud.ConnectionManager@7f2e98d6
[junit4:junit4]   2> 6323 T1870 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:38313
[junit4:junit4]   2> 6323 T1813 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 6325 T1870 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:38313, initiating session
[junit4:junit4]   2> 6325 T1815 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:38348
[junit4:junit4]   2> 6325 T1815 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:38348
[junit4:junit4]   2> 6328 T1817 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c430102f0005 with negotiated timeout 8000 for client /140.211.11.196:38348
[junit4:junit4]   2> 6328 T1870 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:38313, sessionid = 0x139c430102f0005, negotiated timeout = 8000
[junit4:junit4]   2> 6328 T1871 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f2e98d6 name:ZooKeeperConnection Watcher:127.0.0.1:38313/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 6328 T1813 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 6330 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0005 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6339 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0005 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6341 T1813 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38347_solr
[junit4:junit4]   2> 6341 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0005 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:38347_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:38347_solr
[junit4:junit4]   2> 6343 T1813 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38347_solr
[junit4:junit4]   2> 6346 T1847 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 6346 T1859 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 6346 T1833 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 6346 T1813 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 6347 T1813 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 6347 T1813 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 6348 T1813 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 6349 T1813 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 6349 T1813 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 6350 T1813 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 6350 T1813 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 6351 T1813 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 6351 T1813 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 6363 T1813 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 6370 T1813 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 6371 T1813 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 6372 T1813 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 6372 T1813 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 6374 T1813 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 6375 T1813 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 6376 T1813 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 6431 T1813 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 6511 T1813 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 6612 T1813 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 6621 T1813 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 6664 T1834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6677 T1847 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6677 T1833 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6677 T1859 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6677 T1871 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7318 T1813 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 7330 T1813 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 7334 T1813 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 7347 T1813 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 7352 T1813 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 7357 T1813 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 7359 T1813 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 7360 T1813 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty3/
[junit4:junit4]   2> 7360 T1813 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@10e61c47
[junit4:junit4]   2> 7362 T1813 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty3/index/
[junit4:junit4]   2> 7363 T1813 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 7364 T1813 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty3/index forceNew:false
[junit4:junit4]   2> 7370 T1813 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@3edcd3fb; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 7371 T1813 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 7372 T1813 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 7375 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 7376 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 7376 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 7377 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 7378 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 7378 T1813 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 7379 T1813 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 7380 T1813 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 7381 T1813 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 7382 T1813 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 7382 T1813 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 7383 T1813 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 7384 T1813 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 7384 T1813 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 7385 T1813 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 7386 T1813 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 7386 T1813 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7387 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7388 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7389 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7389 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7390 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7391 T1813 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7392 T1813 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 7392 T1813 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 7396 T1813 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 7401 T1813 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 7402 T1813 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> 7406 T1813 oass.SolrIndexSearcher.<init> Opening Searcher@5db2a769 main
[junit4:junit4]   2> 7407 T1813 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 7408 T1813 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 7408 T1813 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 7415 T1813 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 7471 T1872 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5db2a769 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 7685 T1834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7690 T1833 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7690 T1871 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7690 T1859 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7690 T1847 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7978 T1813 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 7979 T1813 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:38347/solr shardId:shard1
[junit4:junit4]   2> 7982 T1813 oasc.ZkController.register We are http://127.0.0.1:38347/solr/collection1/ and leader is http://127.0.0.1:38332/solr/collection1/
[junit4:junit4]   2> 7982 T1813 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38347/solr
[junit4:junit4]   2> 7983 T1813 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 7983 T1813 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C205 name=collection1 org.apache.solr.core.SolrCore@33d944bb url=http://127.0.0.1:38347/solr/collection1 node=127.0.0.1:38347_solr
[junit4:junit4]   2> 7985 T1873 C205 P38347 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 7985 T1873 C205 P38347 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 7985 T1813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7987 T1873 C205 P38347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 7987 T1813 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0
[junit4:junit4]   2> 7987 T1813 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 7988 T1813 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 8005 T1813 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 8008 T1813 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:38353
[junit4:junit4]   2> 8009 T1813 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8009 T1813 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 8010 T1813 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 8060 T1813 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 8061 T1813 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8061 T1813 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 8062 T1813 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 8062 T1813 oasc.CoreContainer.<init> New CoreContainer 984171558
[junit4:junit4]   2> 8063 T1813 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 8063 T1813 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 8100 T1813 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 8117 T1813 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:38313/solr
[junit4:junit4]   2> 8117 T1813 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:38313/solr sessionTimeout=8000 watcher=org.apache.solr.common.cloud.ConnectionManager@4616b6a2
[junit4:junit4]   2> 8118 T1883 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:38313
[junit4:junit4]   2> 8118 T1813 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8120 T1883 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:38313, initiating session
[junit4:junit4]   2> 8120 T1815 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:38354
[junit4:junit4]   2> 8120 T1815 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:38354
[junit4:junit4]   2> 8122 T1817 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c430102f0006 with negotiated timeout 8000 for client /140.211.11.196:38354
[junit4:junit4]   2> 8122 T1883 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:38313, sessionid = 0x139c430102f0006, negotiated timeout = 8000
[junit4:junit4]   2> 8122 T1884 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4616b6a2 name:ZooKeeperConnection Watcher:127.0.0.1:38313/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8123 T1813 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8124 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0006 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8125 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0006 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8132 T1813 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38353_solr
[junit4:junit4]   2> 8133 T1818 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c430102f0006 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:38353_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:38353_solr
[junit4:junit4]   2> 8134 T1813 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38353_solr
[junit4:junit4]   2> 8136 T1847 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 8136 T1833 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 8136 T1859 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 8136 T1871 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 8137 T1813 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 8137 T1813 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 8138 T1813 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 8138 T1813 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 8139 T1813 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 8139 T1813 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 8140 T1813 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 8141 T1813 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 8141 T1813 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 8142 T1813 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 8154 T1813 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 8162 T1813 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 8162 T1813 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 8163 T1813 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 8164 T1813 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 8165 T1813 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 8167 T1813 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 8168 T1813 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 8203 T1834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8215 T1833 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8215 T1884 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8215 T1871 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8215 T1859 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8215 T1847 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8255 T1813 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 8339 T1813 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 8440 T1813 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 8449 T1813 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 9141 T1813 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 9154 T1813 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 9158 T1813 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 9171 T1813 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 9177 T1813 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 9182 T1813 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 9183 T1813 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 9184 T1813 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty4/
[junit4:junit4]   2> 9185 T1813 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@10e61c47
[junit4:junit4]   2> 9186 T1813 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty4/index/
[junit4:junit4]   2> 9187 T1813 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 9188 T1813 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty4/index forceNew:false
[junit4:junit4]   2> 9200 T1813 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@d3589db; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9201 T1813 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 9202 T1813 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 9205 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 9206 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 9207 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 9207 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 9208 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 9209 T1813 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 9209 T1813 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 9210 T1813 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 9211 T1813 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 9212 T1813 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 9213 T1813 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 9214 T1813 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 9214 T1813 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 9215 T1813 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 9216 T1813 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 9216 T1813 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 9217 T1813 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9218 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9219 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9219 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9220 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9221 T1813 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9222 T1813 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9223 T1813 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 9223 T1813 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 9227 T1813 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 9233 T1813 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 9234 T1813 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> 9238 T1813 oass.SolrIndexSearcher.<init> Opening Searcher@34a6050e main
[junit4:junit4]   2> 9240 T1813 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 9240 T1813 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 9241 T1813 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 9290 T1813 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 9520 T1885 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@34a6050e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 9724 T1834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9737 T1833 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9737 T1884 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9737 T1871 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9737 T1847 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9737 T1859 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10044 T1813 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 10045 T1813 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:38353/solr shardId:shard2
[junit4:junit4]   2> 10052 T1813 oasc.ZkController.register We are http://127.0.0.1:38353/solr/collection1/ and leader is http://127.0.0.1:38342/solr/collection1/
[junit4:junit4]   2> 10052 T1813 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38353/solr
[junit4:junit4]   2> 10053 T1813 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 10053 T1813 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C206 name=collection1 org.apache.solr.core.SolrCore@1ba6334f url=http://127.0.0.1:38353/solr/collection1 node=127.0.0.1:38353_solr
[junit4:junit4]   2> 10055 T1886 C206 P38353 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 10055 T1886 C206 P38353 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 10055 T1813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10057 T1886 C206 P38353 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 10057 T1813 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0
[junit4:junit4]   2> 10058 T1813 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 10058 T1813 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 10079 T1813 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:38313/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@4d60f50b
[junit4:junit4]   2> 10081 T1887 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:38313
[junit4:junit4]   2> 10080 T1813 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 10082 T1887 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:38313, initiating session
[junit4:junit4]   2> 10082 T1815 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:38359
[junit4:junit4]   2> 10082 T1815 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:38359
[junit4:junit4]   2> 10084 T1817 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c430102f0007 with negotiated timeout 10000 for client /140.211.11.196:38359
[junit4:junit4]   2> 10084 T1887 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:38313, sessionid = 0x139c430102f0007, negotiated timeout = 10000
[junit4:junit4]   2> 10084 T1888 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4d60f50b name:ZooKeeperConnection Watcher:127.0.0.1:38313/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 10085 T1813 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 10086 T1813 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 10090 T1813 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:true
[junit4:junit4]   2> 10090 T1813 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 10102 T1813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> ASYNC  NEW_CORE C207 name=collection1 org.apache.solr.core.SolrCore@3c6cd470 url=http://127.0.0.1:38316/solr/collection1 node=127.0.0.1:38316_solr
[junit4:junit4]   2> 10120 T1825 C207 P38316 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@32b6e245; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10121 T1825 C207 P38316 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 10125 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[1 (1413078065306664960)]} 0 10
[junit4:junit4]   2> 10126 T1813 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:38313/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@79d5ca82
[junit4:junit4]   2> 10128 T1889 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:38313
[junit4:junit4]   2> 10128 T1813 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 10129 T1889 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:38313, initiating session
[junit4:junit4]   2> 10129 T1815 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:38361
[junit4:junit4]   2> 10129 T1815 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:38361
[junit4:junit4]   2> 10131 T1817 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c430102f0008 with negotiated timeout 10000 for client /140.211.11.196:38361
[junit4:junit4]   2> 10131 T1889 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:38313, sessionid = 0x139c430102f0008, negotiated timeout = 10000
[junit4:junit4]   2> 10131 T1890 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@79d5ca82 name:ZooKeeperConnection Watcher:127.0.0.1:38313/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 10131 T1813 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 10132 T1813 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> ASYNC  NEW_CORE C208 name=collection1 org.apache.solr.core.SolrCore@5dee92c5 url=http://127.0.0.1:38332/solr/collection1 node=127.0.0.1:38332_solr
[junit4:junit4]   2> 10156 T1840 C208 P38332 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2a63471c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10157 T1840 C208 P38332 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2>  C205_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:38347_solr, base_url=http://127.0.0.1:38347/solr}
[junit4:junit4]   2> 10177 T1863 C205 P38347 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@3edcd3fb; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10178 T1863 C205 P38347 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 10182 T1863 C205 P38347 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38332/solr/collection1/&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 10183 T1840 C208 P38332 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=31 
[junit4:junit4]   2> ASYNC  NEW_CORE C209 name=collection1 org.apache.solr.core.SolrCore@138d134f url=http://127.0.0.1:38342/solr/collection1 node=127.0.0.1:38342_solr
[junit4:junit4]   2> 10184 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[1]} 0 40
[junit4:junit4]   2> 10185 T1813 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):1440
[junit4:junit4]   2> 10186 T1813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10241 T1834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10254 T1890 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10254 T1871 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10254 T1847 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10254 T1859 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10254 T1888 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10254 T1833 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10254 T1884 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11188 T1813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12190 T1813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13192 T1813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14194 T1813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15007 T1873 C205 P38347 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:38332/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 15008 T1873 C205 P38347 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:38347/solr START replicas=[http://127.0.0.1:38332/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 15008 T1873 C205 P38347 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 15009 T1873 C205 P38347 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 15009 T1873 C205 P38347 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 15009 T1873 C205 P38347 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty3/tlog/tlog.0000000000000000000 refcount=1}}
[junit4:junit4]   2> 15009 T1873 C205 P38347 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:38332/solr/collection1/. core=collection1
[junit4:junit4]   2> 15010 T1873 C205 P38347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 15010 T1841 C208 P38332 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=0 
[junit4:junit4]   2> 15024 T1842 C208 P38332 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 15103 T1842 C208 P38332 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2a63471c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2a63471c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_MockRandom_0.tib, _0_TestBloomFilteredLucene40Postings_0.tim, _0_TestBloomFilteredLucene40Postings_0.blm, _0_TestBloomFilteredLucene40Postings_0.tip, _0.fnm, _0_MockRandom_0.prx, _0_TestBloomFilteredLucene40Postings_0.prx, _0_nrm.cfs, _0_MockRandom_0.frq, _0_Lucene40WithOrds_0.tii, _0_MockRandom_0.sd, _0_Lucene40WithOrds_0.frq, _0_SimpleText_0.pst, _0_nrm.cfe, _0_MockRandom_0.tii, segments_2, _0_TestBloomFilteredLucene40Postings_0.frq, _0.fdx, _0_Lucene40WithOrds_0.prx, _0.si, _0_Lucene40WithOrds_0.tib, _0.fdt]
[junit4:junit4]   2> 15103 T1842 C208 P38332 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 15119 T1842 C208 P38332 oass.SolrIndexSearcher.<init> Opening Searcher@4c4dca3e main
[junit4:junit4]   2> 15119 T1842 C208 P38332 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15121 T1848 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4c4dca3e main{StandardDirectoryReader(segments_2:3 _0(4.0.0.2):C1)}
[junit4:junit4]   2> 15121 T1842 C208 P38332 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 97
[junit4:junit4]   2> 15122 T1873 C205 P38347 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 15123 T1873 C205 P38347 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 15125 T1843 C208 P38332 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 15126 T1843 C208 P38332 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15126 T1873 C205 P38347 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 15127 T1873 C205 P38347 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 15127 T1873 C205 P38347 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 15132 T1843 C208 P38332 REQ /replication {command=filelist&generation=2&wt=javabin&qt=/replication&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15133 T1873 C205 P38347 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 22
[junit4:junit4]   2> 15139 T1873 C205 P38347 oash.SnapPuller.fetchLatestIndex Starting download to ./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty3/index.20120914095102978 fullCopy=true
[junit4:junit4]   2> 15143 T1843 C208 P38332 REQ /replication {file=_0_TestBloomFilteredLucene40Postings_0.tim&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15149 T1843 C208 P38332 REQ /replication {file=_0_MockRandom_0.tib&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15154 T1843 C208 P38332 REQ /replication {file=_0_TestBloomFilteredLucene40Postings_0.tip&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15159 T1843 C208 P38332 REQ /replication {file=_0_TestBloomFilteredLucene40Postings_0.blm&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15164 T1843 C208 P38332 REQ /replication {file=_0.fnm&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15169 T1843 C208 P38332 REQ /replication {file=_0_MockRandom_0.prx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15174 T1843 C208 P38332 REQ /replication {file=_0_TestBloomFilteredLucene40Postings_0.prx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15178 T1843 C208 P38332 REQ /replication {file=_0_nrm.cfs&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15182 T1843 C208 P38332 REQ /replication {file=_0_MockRandom_0.sd&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15186 T1843 C208 P38332 REQ /replication {file=_0_Lucene40WithOrds_0.tii&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15190 T1843 C208 P38332 REQ /replication {file=_0_MockRandom_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15195 T1843 C208 P38332 REQ /replication {file=_0_Lucene40WithOrds_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15196 T1813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15201 T1843 C208 P38332 REQ /replication {file=_0_nrm.cfe&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15205 T1843 C208 P38332 REQ /replication {file=_0_SimpleText_0.pst&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15209 T1843 C208 P38332 REQ /replication {file=segments_2&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15214 T1843 C208 P38332 REQ /replication {file=_0_MockRandom_0.tii&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15219 T1843 C208 P38332 REQ /replication {file=_0.fdx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15223 T1843 C208 P38332 REQ /replication {file=_0_TestBloomFilteredLucene40Postings_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15227 T1843 C208 P38332 REQ /replication {file=_0_Lucene40WithOrds_0.prx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15231 T1843 C208 P38332 REQ /replication {file=_0.si&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15235 T1843 C208 P38332 REQ /replication {file=_0_Lucene40WithOrds_0.tib&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15239 T1843 C208 P38332 REQ /replication {file=_0.fdt&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 15240 T1873 C205 P38347 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 15241 T1873 C205 P38347 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20120914095102978
[junit4:junit4]   2> 15242 T1873 C205 P38347 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 15243 T1873 C205 P38347 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 15243 T1873 C205 P38347 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 15248 T1873 C205 P38347 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty3/index/ new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty3/index.20120914095102978
[junit4:junit4]   2> 15248 T1873 C205 P38347 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty3/index.20120914095102978 forceNew:true
[junit4:junit4]   2> 15259 T1873 C205 P38347 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty3/index.20120914095102978 lockFactory=org.apache.lucene.store.NativeFSLockFactory@357ae7c4; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_MockRandom_0.tib, _0_TestBloomFilteredLucene40Postings_0.tim, _0_TestBloomFilteredLucene40Postings_0.blm, _0_TestBloomFilteredLucene40Postings_0.tip, _0.fnm, _0_MockRandom_0.prx, _0_TestBloomFilteredLucene40Postings_0.prx, _0_nrm.cfs, _0_MockRandom_0.frq, _0_Lucene40WithOrds_0.tii, _0_MockRandom_0.sd, _0_Lucene40WithOrds_0.frq, _0_nrm.cfe, _0_SimpleText_0.pst, _0_MockRandom_0.tii, segments_2, _0.fdx, _0_TestBloomFilteredLucene40Postings_0.frq, _0_Lucene40WithOrds_0.prx, _0.si, _0_Lucene40WithOrds_0.tib, _0.fdt]
[junit4:junit4]   2> 15260 T1873 C205 P38347 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 15260 T1873 C205 P38347 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 15264 T1873 C205 P38347 oass.SolrIndexSearcher.<init> Opening Searcher@675b8d2b main
[junit4:junit4]   2> 15266 T1872 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@675b8d2b main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 15267 T1872 oasc.CachingDirectoryFactory.close Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty3/index
[junit4:junit4]   2> 15267 T1872 oash.SnapPuller$2.onClose removing old index directory ./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty3/index
[junit4:junit4]   2> 15269 T1873 C205 P38347 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 15270 T1873 C205 P38347 oass.SolrIndexSearcher.<init> Opening Searcher@4ab611c8 main
[junit4:junit4]   2> 15271 T1873 C205 P38347 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15272 T1872 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4ab611c8 main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 15278 T1873 C205 P38347 oasc.RecoveryStrategy.replay Replaying buffered documents. core=collection1
[junit4:junit4]   2> 15279 T1895 C205 P38347 oasu.UpdateLog$LogReplayer.doReplay WARNING Starting log replay tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty3/tlog/tlog.0000000000000000000 refcount=2} active=true starting pos=425
[junit4:junit4]   2> 15284 T1895 C205 P38347 oasu.DirectUpdateHandler2.commit start commit{flags=2,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 15287 T1895 C205 P38347 oass.SolrIndexSearcher.<init> Opening Searcher@585ff86a main
[junit4:junit4]   2> 15287 T1895 C205 P38347 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15288 T1872 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@585ff86a main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 15289 T1895 C205 P38347 oasu.UpdateLog$LogReplayer.run WARNING Log replay finished. recoveryInfo=RecoveryInfo{adds=0 deletes=0 deleteByQuery=0 errors=0 positionOfStart=425}
[junit4:junit4]   2> 15289 T1873 C205 P38347 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 15291 T1873 C205 P38347 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 15775 T1834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15787 T1890 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15787 T1888 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15788 T1847 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15788 T1833 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15788 T1859 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15788 T1871 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15788 T1884 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 16198 T1813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C206_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:38353_solr, base_url=http://127.0.0.1:38353/solr}
[junit4:junit4]   2> 17083 T1886 C206 P38353 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:38342/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 17084 T1886 C206 P38353 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:38353/solr START replicas=[http://127.0.0.1:38342/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 17084 T1886 C206 P38353 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 17084 T1886 C206 P38353 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 17085 T1886 C206 P38353 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 17085 T1886 C206 P38353 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 17085 T1886 C206 P38353 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:38342/solr/collection1/. core=collection1
[junit4:junit4]   2> 17085 T1886 C206 P38353 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 17087 T1853 C209 P38342 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 17101 T1854 C209 P38342 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 17105 T1854 C209 P38342 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@67df730e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 17106 T1854 C209 P38342 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 17107 T1854 C209 P38342 oass.SolrIndexSearcher.<init> Opening Searcher@5c4efbd9 main
[junit4:junit4]   2> 17108 T1854 C209 P38342 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 17110 T1860 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5c4efbd9 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 17110 T1854 C209 P38342 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 10
[junit4:junit4]   2> 17111 T1886 C206 P38353 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 17111 T1886 C206 P38353 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 17113 T1855 C209 P38342 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 17113 T1855 C209 P38342 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 17118 T1886 C206 P38353 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@d3589db; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 17119 T1886 C206 P38353 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 17120 T1886 C206 P38353 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 17123 T1886 C206 P38353 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@d3589db; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@d3589db; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 17123 T1886 C206 P38353 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 17127 T1886 C206 P38353 oass.SolrIndexSearcher.<init> Opening Searcher@4affc007 main
[junit4:junit4]   2> 17127 T1886 C206 P38353 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 17129 T1885 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4affc007 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 17129 T1886 C206 P38353 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 17130 T1886 C206 P38353 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 17131 T1886 C206 P38353 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 17200 T1813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 17295 T1834 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 17307 T1888 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 17307 T1890 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 17307 T1871 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 17307 T1859 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 17307 T1847 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 17307 T1833 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 17307 T1884 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 18202 T1813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18205 T1825 C207 P38316 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 18261 T1825 C207 P38316 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@32b6e245; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@32b6e245; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_MockRandom_0.tib, _0_TestBloomFilteredLucene40Postings_0.tim, _0_TestBloomFilteredLucene40Postings_0.blm, _0_TestBloomFilteredLucene40Postings_0.tip, _0.fnm, _0_TestBloomFilteredLucene40Postings_0.prx, _0_nrm.cfs, _0_MockRandom_0.skp, _0_MockRandom_0.sd, _0_MockRandom_0.frq, _0_Lucene40WithOrds_0.tii, _0_MockRandom_0.tiv, _0_Lucene40WithOrds_0.frq, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0_nrm.cfe, _0_SimpleText_0.pst, segments_2, _0.fdx, _0_TestBloomFilteredLucene40Postings_0.frq, _0_Lucene40WithOrds_0.prx, _0_MockRandom_0.pyl, _0.si, _0_Lucene40WithOrds_0.tib, _0.fdt]
[junit4:junit4]   2> 18262 T1825 C207 P38316 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 18279 T1825 C207 P38316 oass.SolrIndexSearcher.<init> Opening Searcher@39bff54b main
[junit4:junit4]   2> 18280 T1825 C207 P38316 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18281 T1836 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@39bff54b main{StandardDirectoryReader(segments_2:3 _0(4.0.0.2):C1)}
[junit4:junit4]   2> 18282 T1825 C207 P38316 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 77
[junit4:junit4]   2> 18284 T1844 C208 P38332 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 18294 T1844 C208 P38332 oass.SolrIndexSearcher.<init> Opening Searcher@51605227 main
[junit4:junit4]   2> 18295 T1844 C208 P38332 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18296 T1848 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@51605227 main{StandardDirectoryReader(segments_2:3 _0(4.0.0.2):C1)}
[junit4:junit4]   2> 18296 T1844 C208 P38332 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:38347/solr/collection1/, StdNode: http://127.0.0.1:38342/solr/collection1/, StdNode: http://127.0.0.1:38353/solr/collection1/]
[junit4:junit4]   2> 18298 T1856 C209 P38342 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2>  C205_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:38347_solr, base_url=http://127.0.0.1:38347/solr}
[junit4:junit4]   2> 18301 T1863 C205 P38347 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 18304 T1863 C205 P38347 oass.SolrIndexSearcher.<init> Opening Searcher@7a1aceff main
[junit4:junit4]   2> 18304 T1863 C205 P38347 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18304 T1856 C209 P38342 oass.SolrIndexSearcher.<init> Opening Searcher@f5c5afb main
[junit4:junit4]   2> 18305 T1856 C209 P38342 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18305 T1872 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7a1aceff main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 18306 T1863 C205 P38347 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&softCommit=false&version=2} {commit=} 0 5
[junit4:junit4]   2> 18306 T1860 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f5c5afb main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 18307 T1856 C209 P38342 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&softCommit=false&version=2} {commit=} 0 9
[junit4:junit4]   2>  C206_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:38353_solr, base_url=http://127.0.0.1:38353/solr}
[junit4:junit4]   2> 18309 T1876 C206 P38353 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 18313 T1876 C206 P38353 oass.SolrIndexSearcher.<init> Opening Searcher@5a03fccb main
[junit4:junit4]   2> 18313 T1876 C206 P38353 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18315 T1885 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5a03fccb main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 18315 T1876 C206 P38353 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&softCommit=false&version=2} {commit=} 0 6
[junit4:junit4]   2> 18316 T1844 C208 P38332 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 32
[junit4:junit4]   2> 18322 T1826 C207 P38316 REQ /select {fl=id,score&shard.url=127.0.0.1:38316/solr/collection1/&NOW=1347616266164&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 18325 T1826 C207 P38316 REQ /select {shard.url=127.0.0.1:38316/solr/collection1/&NOW=1347616266164&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 18327 T1825 C207 P38316 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=8 
[junit4:junit4]   2> 18328 T1813 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:38313/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@49a7f00a
[junit4:junit4]   2> 18329 T1901 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:38313
[junit4:junit4]   2> 18329 T1813 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 18330 T1901 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:38313, initiating session
[junit4:junit4]   2> 18330 T1815 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:38387
[junit4:junit4]   2> 18330 T1815 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:38387
[junit4:junit4]   2> 18332 T1817 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c430102f0009 with negotiated timeout 10000 for client /140.211.11.196:38387
[junit4:junit4]   2> 18332 T1901 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:38313, sessionid = 0x139c430102f0009, negotiated timeout = 10000
[junit4:junit4]   2> 18332 T1902 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@49a7f00a name:ZooKeeperConnection Watcher:127.0.0.1:38313/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 18332 T1813 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 18333 T1813 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 18335 T1818 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139c430102f0009
[junit4:junit4]   2> 18336 T1902 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 18336 T1815 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:38387 which had sessionid 0x139c430102f0009
[junit4:junit4]   2> 18336 T1813 oaz.ZooKeeper.close Session: 0x139c430102f0009 closed
[junit4:junit4]   2> 18338 T1845 C208 P38332 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 18341 T1857 C209 P38342 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 18347 T1839 C208 P38332 REQ /select {fl=id,score&shard.url=127.0.0.1:38332/solr/collection1/|127.0.0.1:38347/solr/collection1/&NOW=1347616266189&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 18347 T1877 C206 P38353 REQ /select {fl=id,score&shard.url=127.0.0.1:38342/solr/collection1/|127.0.0.1:38353/solr/collection1/&NOW=1347616266189&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 18350 T1839 C208 P38332 REQ /select {shard.url=127.0.0.1:38332/solr/collection1/|127.0.0.1:38347/solr/collection1/&NOW=1347616266189&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 18351 T1844 C208 P38332 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=7 
[junit4:junit4]   2> 18359 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[2 (1413078073947979776)]} 0 4
[junit4:junit4]   2> 18375 T1876 C206 P38353 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38342/solr/collection1/&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 18376 T1856 C209 P38342 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=11 
[junit4:junit4]   2> 18377 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[2]} 0 15
[junit4:junit4]   2> 18382 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[3 (1413078073974194176)]} 0 2
[junit4:junit4]   2> 18391 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 18392 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[3 (1413078073978388480)]} 0 7
[junit4:junit4]   2> 18397 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[4 (1413078073988874240)]} 0 1
[junit4:junit4]   2> 18409 T1863 C205 P38347 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 18409 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[4 (1413078073993068544)]} 0 10
[junit4:junit4]   2> 18414 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[5 (1413078074006700032)]} 0 2
[junit4:junit4]   2> 18422 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 18422 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[5 (1413078074010894336)]} 0 6
[junit4:junit4]   2> 18426 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[6 (1413078074020331520)]} 0 1
[junit4:junit4]   2> 18438 T1876 C206 P38353 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38342/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 18438 T1856 C209 P38342 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 18439 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[6]} 0 10
[junit4:junit4]   2> 18444 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[7 (1413078074038157312)]} 0 2
[junit4:junit4]   2> 18455 T1876 C206 P38353 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38342/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 18455 T1856 C209 P38342 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 18456 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[7]} 0 10
[junit4:junit4]   2> 18461 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[8 (1413078074055983104)]} 0 2
[junit4:junit4]   2> 18473 T1863 C205 P38347 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38332/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 18473 T1840 C208 P38332 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 18474 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[8]} 0 10
[junit4:junit4]   2> 18478 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[9 (1413078074074857472)]} 0 1
[junit4:junit4]   2> 18489 T1876 C206 P38353 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38342/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 18490 T1856 C209 P38342 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 18491 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[9]} 0 10
[junit4:junit4]   2> 18495 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[10 (1413078074092683264)]} 0 1
[junit4:junit4]   2> 18504 T1863 C205 P38347 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 18505 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[10 (1413078074096877568)]} 0 7
[junit4:junit4]   2> 18522 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[11 (1413078074107363328)]} 0 14
[junit4:junit4]   2> 18534 T1863 C205 P38347 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38332/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 18535 T1840 C208 P38332 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 18535 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[11]} 0 10
[junit4:junit4]   2> 18541 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[12 (1413078074138820608)]} 0 3
[junit4:junit4]   2> 18550 T1863 C205 P38347 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 18551 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[12 (1413078074146160640)]} 0 7
[junit4:junit4]   2> 18556 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[13 (1413078074155597824)]} 0 2
[junit4:junit4]   2> 18565 T1863 C205 P38347 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 18566 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[13 (1413078074161889280)]} 0 7
[junit4:junit4]   2> 18570 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[14 (1413078074171326464)]} 0 1
[junit4:junit4]   2> 18582 T1863 C205 P38347 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38332/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 18582 T1840 C208 P38332 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 18583 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[14]} 0 10
[junit4:junit4]   2> 18587 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[15 (1413078074189152256)]} 0 1
[junit4:junit4]   2> 18595 T1863 C205 P38347 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 18596 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[15 (1413078074194395136)]} 0 6
[junit4:junit4]   2> 18600 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[16 (1413078074202783744)]} 0 1
[junit4:junit4]   2> 18609 T1863 C205 P38347 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 18609 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[16 (1413078074206978048)]} 0 6
[junit4:junit4]   2> 18615 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[17 (1413078074217463808)]} 0 3
[junit4:junit4]   2> 18629 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 18629 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[17 (1413078074224803840)]} 0 10
[junit4:junit4]   2> 18633 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[100 (1413078074237386752)]} 0 1
[junit4:junit4]   2> 18672 T1863 C205 P38347 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38332/solr/collection1/&wt=javabin&version=2} status=0 QTime=13 
[junit4:junit4]   2> 18672 T1840 C208 P38332 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=33 
[junit4:junit4]   2> 18673 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[100]} 0 37
[junit4:junit4]   2> 18677 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[101 (1413078074283524096)]} 0 1
[junit4:junit4]   2> 18689 T1863 C205 P38347 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38332/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 18690 T1840 C208 P38332 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 18691 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[101]} 0 11
[junit4:junit4]   2> 18695 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[102 (1413078074302398464)]} 0 1
[junit4:junit4]   2> 18705 T1863 C205 P38347 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38332/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 18706 T1840 C208 P38332 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 18707 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[102]} 0 9
[junit4:junit4]   2> 18723 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[103 (1413078074319175680)]} 0 13
[junit4:junit4]   2> 18733 T1876 C206 P38353 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38342/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 18734 T1856 C209 P38342 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 18734 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[103]} 0 8
[junit4:junit4]   2> 18739 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[104 (1413078074347487232)]} 0 2
[junit4:junit4]   2> 18746 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 18747 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[104 (1413078074352730112)]} 0 5
[junit4:junit4]   2> 18751 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[105 (1413078074361118720)]} 0 1
[junit4:junit4]   2> 18780 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=11 
[junit4:junit4]   2> 18781 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[105 (1413078074365313024)]} 0 27
[junit4:junit4]   2> 18785 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[106 (1413078074396770304)]} 0 1
[junit4:junit4]   2> 18798 T1876 C206 P38353 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38342/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 18799 T1856 C209 P38342 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 18799 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[106]} 0 11
[junit4:junit4]   2> 18803 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[107 (1413078074415644672)]} 0 1
[junit4:junit4]   2> 18814 T1863 C205 P38347 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38332/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 18815 T1840 C208 P38332 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 18816 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[107]} 0 10
[junit4:junit4]   2> 18820 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[108 (1413078074433470464)]} 0 1
[junit4:junit4]   2> 18827 T1863 C205 P38347 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 18828 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[108 (1413078074437664768)]} 0 5
[junit4:junit4]   2> 18832 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[109 (1413078074446053376)]} 0 1
[junit4:junit4]   2> 18839 T1863 C205 P38347 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 18840 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[109 (1413078074450247680)]} 0 5
[junit4:junit4]   2> 18844 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[110 (1413078074458636288)]} 0 1
[junit4:junit4]   2> 18851 T1863 C205 P38347 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 18852 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[110 (1413078074462830592)]} 0 5
[junit4:junit4]   2> 18856 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[111 (1413078074471219200)]} 0 1
[junit4:junit4]   2> 18865 T1863 C205 P38347 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38332/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 18866 T1840 C208 P38332 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 18866 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[111]} 0 7
[junit4:junit4]   2> 18870 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[112 (1413078074485899264)]} 0 1
[junit4:junit4]   2> 18880 T1876 C206 P38353 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38342/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 18881 T1856 C209 P38342 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 18881 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[112]} 0 8
[junit4:junit4]   2> 18896 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[113 (1413078074501627904)]} 0 12
[junit4:junit4]   2> 18905 T1863 C205 P38347 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38332/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 18906 T1840 C208 P38332 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 18906 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[113]} 0 8
[junit4:junit4]   2> 18911 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[114 (1413078074527842304)]} 0 2
[junit4:junit4]   2> 18920 T1863 C205 P38347 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38332/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 18921 T1840 C208 P38332 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 18921 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[114]} 0 7
[junit4:junit4]   2> 18925 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[115 (1413078074543570944)]} 0 1
[junit4:junit4]   2> 18935 T1876 C206 P38353 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38342/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 18936 T1856 C209 P38342 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 18936 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[115]} 0 8
[junit4:junit4]   2> 18940 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[116 (1413078074559299584)]} 0 1
[junit4:junit4]   2> 18947 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 18948 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[116 (1413078074563493888)]} 0 5
[junit4:junit4]   2> 18952 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[117 (1413078074571882496)]} 0 1
[junit4:junit4]   2> 18959 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 18960 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[117 (1413078074576076800)]} 0 5
[junit4:junit4]   2> 18964 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[118 (1413078074584465408)]} 0 1
[junit4:junit4]   2> 18993 T1863 C205 P38347 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38332/solr/collection1/&wt=javabin&version=2} status=0 QTime=11 
[junit4:junit4]   2> 18994 T1840 C208 P38332 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=24 
[junit4:junit4]   2> 18995 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[118]} 0 28
[junit4:junit4]   2> 18999 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[119 (1413078074621165568)]} 0 1
[junit4:junit4]   2> 19007 T1876 C206 P38353 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38342/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19008 T1856 C209 P38342 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 19008 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[119]} 0 6
[junit4:junit4]   2> 19012 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[120 (1413078074634797056)]} 0 1
[junit4:junit4]   2> 19019 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19020 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[120 (1413078074638991360)]} 0 5
[junit4:junit4]   2> 19024 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[121 (1413078074647379968)]} 0 1
[junit4:junit4]   2> 19033 T1876 C206 P38353 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38342/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19034 T1856 C209 P38342 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 19034 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[121]} 0 7
[junit4:junit4]   2> 19038 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[122 (1413078074662060032)]} 0 1
[junit4:junit4]   2> 19047 T1863 C205 P38347 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19048 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[122 (1413078074666254336)]} 0 7
[junit4:junit4]   2> 19061 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[123 (1413078074676740096)]} 0 10
[junit4:junit4]   2> 19068 T1863 C205 P38347 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19069 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[123 (1413078074690371584)]} 0 5
[junit4:junit4]   2> 19074 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[124 (1413078074698760192)]} 0 2
[junit4:junit4]   2> 19081 T1863 C205 P38347 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19082 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[124 (1413078074704003072)]} 0 5
[junit4:junit4]   2> 19086 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[125 (1413078074712391680)]} 0 1
[junit4:junit4]   2> 19095 T1863 C205 P38347 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38332/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19096 T1840 C208 P38332 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 19097 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[125]} 0 8
[junit4:junit4]   2> 19101 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[126 (1413078074728120320)]} 0 1
[junit4:junit4]   2> 19108 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19110 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[126 (1413078074732314624)]} 0 6
[junit4:junit4]   2> 19115 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[127 (1413078074742800384)]} 0 2
[junit4:junit4]   2> 19145 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=11 
[junit4:junit4]   2> 19145 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[127 (1413078074748043264)]} 0 26
[junit4:junit4]   2> 19150 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[128 (1413078074779500544)]} 0 1
[junit4:junit4]   2> 19163 T1876 C206 P38353 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38342/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19164 T1856 C209 P38342 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 19165 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[128]} 0 12
[junit4:junit4]   2> 19169 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[129 (1413078074799423488)]} 0 1
[junit4:junit4]   2> 19177 T1863 C205 P38347 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19178 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[129 (1413078074803617792)]} 0 6
[junit4:junit4]   2> 19182 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[130 (1413078074813054976)]} 0 1
[junit4:junit4]   2> 19189 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19190 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[130 (1413078074817249280)]} 0 5
[junit4:junit4]   2> 19194 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[131 (1413078074825637888)]} 0 1
[junit4:junit4]   2> 19201 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19202 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[131 (1413078074829832192)]} 0 5
[junit4:junit4]   2> 19206 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[132 (1413078074838220800)]} 0 1
[junit4:junit4]   2> 19213 T1863 C205 P38347 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19214 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[132 (1413078074842415104)]} 0 5
[junit4:junit4]   2> 19228 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[133 (1413078074850803712)]} 0 11
[junit4:junit4]   2> 19238 T1863 C205 P38347 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38332/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19239 T1840 C208 P38332 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 19240 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[133]} 0 9
[junit4:junit4]   2> 19245 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[134 (1413078074878066688)]} 0 2
[junit4:junit4]   2> 19255 T1876 C206 P38353 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38342/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19256 T1856 C209 P38342 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 19257 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[134]} 0 9
[junit4:junit4]   2> 19261 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[135 (1413078074895892480)]} 0 1
[junit4:junit4]   2> 19270 T1863 C205 P38347 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19271 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[135 (1413078074900086784)]} 0 7
[junit4:junit4]   2> 19275 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[136 (1413078074910572544)]} 0 1
[junit4:junit4]   2> 19283 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19284 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[136 (1413078074914766848)]} 0 6
[junit4:junit4]   2> 19288 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[137 (1413078074924204032)]} 0 1
[junit4:junit4]   2> 19295 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19296 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[137 (1413078074928398336)]} 0 5
[junit4:junit4]   2> 19300 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[138 (1413078074936786944)]} 0 1
[junit4:junit4]   2> 19307 T1863 C205 P38347 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19308 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[138 (1413078074940981248)]} 0 5
[junit4:junit4]   2> 19312 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[139 (1413078074949369856)]} 0 1
[junit4:junit4]   2> 19324 T1876 C206 P38353 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38342/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19325 T1856 C209 P38342 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 19326 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[139]} 0 11
[junit4:junit4]   2> 19331 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[140 (1413078074969292800)]} 0 1
[junit4:junit4]   2> 19342 T1876 C206 P38353 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38342/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19343 T1856 C209 P38342 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 19344 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[140]} 0 10
[junit4:junit4]   2> 19348 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[141 (1413078074987118592)]} 0 1
[junit4:junit4]   2> 19355 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19356 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[141 (1413078074991312896)]} 0 5
[junit4:junit4]   2> 19360 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[142 (1413078074999701504)]} 0 1
[junit4:junit4]   2> 19447 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 19448 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[142 (1413078075066810368)]} 0 26
[junit4:junit4]   2> 19464 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[143 (1413078075097219072)]} 0 13
[junit4:junit4]   2> 19474 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19475 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[143 (1413078075112947712)]} 0 8
[junit4:junit4]   2> 19480 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[144 (1413078075124482048)]} 0 2
[junit4:junit4]   2> 19490 T1876 C206 P38353 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38342/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19491 T1856 C209 P38342 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 19491 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[144]} 0 8
[junit4:junit4]   2> 19495 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[145 (1413078075141259264)]} 0 1
[junit4:junit4]   2> 19505 T1876 C206 P38353 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38342/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19506 T1856 C209 P38342 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 19507 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[145]} 0 9
[junit4:junit4]   2> 19511 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[146 (1413078075158036480)]} 0 1
[junit4:junit4]   2> 19542 T1863 C205 P38347 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38332/solr/collection1/&wt=javabin&version=2} status=0 QTime=12 
[junit4:junit4]   2> 19543 T1840 C208 P38332 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=26 
[junit4:junit4]   2> 19543 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[146]} 0 29
[junit4:junit4]   2> 19548 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[147 (1413078075196833792)]} 0 1
[junit4:junit4]   2> 19555 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19556 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[147 (1413078075201028096)]} 0 5
[junit4:junit4]   2> 19560 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[148 (1413078075209416704)]} 0 1
[junit4:junit4]   2> 19570 T1863 C205 P38347 REQ /update {distrib.from=http://127.0.0.1:38332/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19571 T1844 C208 P38332 /update {wt=javabin&version=2} {add=[148 (1413078075213611008)]} 0 8
[junit4:junit4]   2> 19575 T1825 C207 P38316 /update {wt=javabin&version=2} {add=[149 (1413078075225145344)]} 0 1
[junit4:junit4]   2> 19582 T1876 C206 P38353 REQ /update {distrib.from=http://127.0.0.1:38342/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19583 T1852 C209 P38342 /update {wt=javabin&version=2} {add=[149 (1413078075229339648)]} 0 5
[junit4:junit4]   2> 19583 T1813 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):1440
[junit4:junit4]   2> 19584 T1813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19587 T1825 C207 P38316 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 19935 T1825 C207 P38316 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@32b6e245; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_MockRandom_0.tib, _0_TestBloomFilteredLucene40Postings_0.tim, _0_TestBloomFilteredLucene40Postings_0.blm, _0_TestBloomFilteredLucene40Postings_0.tip, _0.fnm, _0_TestBloomFilteredLucene40Postings_0.prx, _0_nrm.cfs, _0_MockRandom_0.skp, _0_MockRandom_0.sd, _0_MockRandom_0.frq, _0_Lucene40WithOrds_0.tii, _0_MockRandom_0.tiv, _0_Lucene40WithOrds_0.frq, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0_nrm.cfe, _0_SimpleText_0.pst, segments_2, _0.fdx, _0_TestBloomFilteredLucene40Postings_0.frq, _0_Lucene40WithOrds_0.prx, _0_MockRandom_0.pyl, _0.si, _0_Lucene40WithOrds_0.tib, _0.fdt]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@32b6e245; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[_5_nrm.cfe, _4_TestBloomFilteredLucene40Postings_0.frq, _2_SimpleText_0.pst, _3_TestBloomFilteredLucene40Postings_0.prx, _2_TestBloomFilteredLucene40Postings_0.blm, _7.si, _7_TestBloomFilteredLucene40Postings_0.tip, _3.fdt, _5_Lucene40WithOrds_0.tib, _7_TestBloomFilteredLucene40Postings_0.tim, _7.fnm, _0_Lucene40WithOrds_0.tii, _5_Lucene40WithOrds_0.tii, _0_Lucene40WithOrds_0.frq, _1_Lucene40WithOrds_0.tib, _0_SimpleText_0.pst, _7_Lucene40WithOrds_0.frq, _3_MockRandom_0.skp, _0_TestBloomFilteredLucene40Postings_0.frq, _1_Lucene40WithOrds_0.tii, _0_Lucene40WithOrds_0.tib, _3_TestBloomFilteredLucene40Postings_0.frq, _6_MockRandom_0.skp, _1_Lucene40WithOrds_0.frq, _1_MockRandom_0.tiv, _3_TestBloomFilteredLucene40Postings_0.tim, _0_TestBloomFilteredLucene40Postings_0.blm, _2.fdt, _7.fdx, _1_MockRandom_0.sd, _3_TestBloomFilteredLucene40Postings_0.tip, _2.fdx, _7.fdt, _0_MockRandom_0.skp, _7_MockRandom_0.prx, _5_TestBloomFilteredLucene40Postings_0.frq, _1.fdx, _0_MockRandom_0.frq, _4_MockRandom_0.prx, _1_MockRandom_0.tib, _5_nrm.cfs, _1.fdt, _4_MockRandom_0.sd, _7_MockRandom_0.sd, _3.si, _6.fdt, _3_TestBloomFilteredLucene40Postings_0.blm, _5_Lucene40WithOrds_0.prx, _1_SimpleText_0.pst, _2.si, _4_Lucene40WithOrds_0.tib, _6_MockRandom_0.tip, _4_Lucene40WithOrds_0.tii, _2_MockRandom_0.tip, _6.fdx, _6_MockRandom_0.tim, _2_MockRandom_0.tim, _1_Lucene40WithOrds_0.prx, _3_MockRandom_0.frq, _3.fnm, _4_TestBloomFilteredLucene40Postings_0.prx, _2_nrm.cfe, _6_MockRandom_0.pyl, _5_TestBloomFilteredLucene40Postings_0.blm, _2_MockRandom_0.pyl, _6_MockRandom_0.doc, _2_nrm.cfs, _2_TestBloomFilteredLucene40Postings_0.frq, _4_TestBloomFilteredLucene40Postings_0.blm, _2_Lucene40WithOrds_0.frq, _2.fnm, _3.fdx, _2_MockRandom_0.sd, _2_MockRandom_0.skp, _1.si, _4_TestBloomFilteredLucene40Postings_0.tim, _3_MockRandom_0.pyl, _6.si, _6.fnm, _4_TestBloomFilteredLucene40Postings_0.tip, _0_Lucene40WithOrds_0.prx, _3_Lucene40WithOrds_0.prx, _2_MockRandom_0.doc, _3_MockRandom_0.pos, _6_MockRandom_0.frq, _3_nrm.cfe, _7_TestBloomFilteredLucene40Postings_0.blm, _5.fdt, _2_TestBloomFilteredLucene40Postings_0.prx, _3_Lucene40WithOrds_0.tii, _6_Lucene40WithOrds_0.prx, _4_nrm.cfe, _4.fnm, _1.fnm, _3_Lucene40WithOrds_0.tib, _7_MockRandom_0.tip, _4.fdx, _7_MockRandom_0.tim, _7_MockRandom_0.frq, _5_MockRandom_0.sd, _4_MockRandom_0.tip, _5_TestBloomFilteredLucene40Postings_0.prx, _4_MockRandom_0.tim, _0_TestBloomFilteredLucene40Postings_0.tim, _2_TestBloomFilteredLucene40Postings_0.tim, _0_TestBloomFilteredLucene40Postings_0.tip, _6_Lucene40WithOrds_0.frq, _0.fnm, _7_Lucene40WithOrds_0.tib, _6_Lucene40WithOrds_0.tii, _1_TestBloomFilteredLucene40Postings_0.frq, _2_TestBloomFilteredLucene40Postings_0.tip, _5.si, _5_Lucene40WithOrds_0.frq, _3_nrm.cfs, _7_Lucene40WithOrds_0.tii, _6_MockRandom_0.sd, _3_MockRandom_0.tip, _4_Lucene40WithOrds_0.prx, _6_Lucene40WithOrds_0.tib, _0_MockRandom_0.doc, _3_MockRandom_0.tim, _4_nrm.cfs, _0_MockRandom_0.pos, _1_MockRandom_0.frq, _5_MockRandom_0.frq, _4_Lucene40WithOrds_0.frq, _0_TestBloomFilteredLucene40Postings_0.prx, _3_MockRandom_0.doc, _1_TestBloomFilteredLucene40Postings_0.blm, _6_MockRandom_0.pos, _5_MockRandom_0.tip, _1_TestBloomFilteredLucene40Postings_0.tip, _6_nrm.cfs, _5_MockRandom_0.tim, _2_Lucene40WithOrds_0.prx, _7_nrm.cfs, _7_Lucene40WithOrds_0.prx, _6_TestBloomFilteredLucene40Postings_0.tip, _2_MockRandom_0.pos, _1_TestBloomFilteredLucene40Postings_0.tim, _0.si, _6_TestBloomFilteredLucene40Postings_0.tim, _6_TestBloomFilteredLucene40Postings_0.frq, _1_nrm.cfs, _0_MockRandom_0.tib, _5.fnm, _1_TestBloomFilteredLucene40Postings_0.prx, _7_nrm.cfe, _6_nrm.cfe, _7_TestBloomFilteredLucene40Postings_0.frq, _4.si, _4.fdt, _0_nrm.cfs, _3_Lucene40WithOrds_0.frq, _7_TestBloomFilteredLucene40Postings_0.prx, _1_nrm.cfe, _3_MockRandom_0.sd, _2_Lucene40WithOrds_0.tii, _5_MockRandom_0.prx, _1_MockRandom_0.prx, _0_MockRandom_0.sd, _0_MockRandom_0.tiv, _4_MockRandom_0.frq, _0_nrm.cfe, _5.fdx, _2_MockRandom_0.frq, _6_TestBloomFilteredLucene40Postings_0.blm, _0.fdx, _2_Lucene40WithOrds_0.tib, _6_TestBloomFilteredLucene40Postings_0.prx, _5_TestBloomFilteredLucene40Postings_0.tim, _0_MockRandom_0.pyl, _5_TestBloomFilteredLucene40Postings_0.tip, _0.fdt, segments_3]
[junit4:junit4]   2> 19937 T1825 C207 P38316 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 20029 T1825 C207 P38316 oass.SolrIndexSearcher.<init> Opening Searcher@44edec3e main
[junit4:junit4]   2> 20030 T1825 C207 P38316 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 20032 T1836 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@44edec3e main{StandardDirectoryReader(segments_3:17 _0(4.0.0.2):C1 _1(4.0.0.2):C10 _2(4.0.0.2):C10 _3(4.0.0.2):C10 _4(4.0.0.2):C10 _5(4.0.0.2):C10 _6(4.0.0.2):C10 _7(4.0.0.2):C6)}
[junit4:junit4]   2> 20032 T1825 C207 P38316 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 445
[junit4:junit4]   2> 20035 T1844 C208 P38332 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 20285 T1844 C208 P38332 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2a63471c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_MockRandom_0.tib, _0_TestBloomFilteredLucene40Postings_0.tim, _0_TestBloomFilteredLucene40Postings_0.blm, _0_TestBloomFilteredLucene40Postings_0.tip, _0.fnm, _0_MockRandom_0.prx, _0_TestBloomFilteredLucene40Postings_0.prx, _0_nrm.cfs, _0_MockRandom_0.frq, _0_Lucene40WithOrds_0.tii, _0_MockRandom_0.sd, _0_Lucene40WithOrds_0.frq, _0_SimpleText_0.pst, _0_nrm.cfe, _0_MockRandom_0.tii, segments_2, _0_TestBloomFilteredLucene40Postings_0.frq, _0.fdx, _0_Lucene40WithOrds_0.prx, _0.si, _0_Lucene40WithOrds_0.tib, _0.fdt]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1347616247849/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2a63471c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[_4_TestBloomFilteredLucene40Postings_0.frq, _3_TestBloomFilteredLucene40Postings_0.prx, _3_MockRandom_0.prx, _0_MockRandom_0.prx, _2_TestBloomFilteredLucene40Postings_0.blm, _3.fdt, _0_Lucene40WithOrds_0.tii, _0_Lucene40WithOrds_0.frq, _1_Lucene40WithOrds_0.tib, _0_SimpleText_0.pst, _4_MockRandom_0.pyl, _0_TestBloomFilteredLucene40Postings_0.frq, _1_Lucene40WithOrds_0.tii, _0_Lucene40WithOrds_0.tib, _3_TestBloomFilteredLucene40Postings_0.frq, _1_Lucene40WithOrds_0.frq, _1_MockRandom_0.tiv, _3_TestBloomFilteredLucene40Postings_0.tim, _0_TestBloomFilteredLucene40Postings_0.blm, _2.fdt, _1_MockRandom_0.sd, _3_TestBloomFilteredLucene40Postings_0.tip, _2.fdx, _1.fdx, _0_MockRandom_0.frq, _1_MockRandom_0.tib, _1.fdt, _4_MockRandom_0.sd, _3.si, _3_TestBloomFilteredLucene40Postings_0.blm, _1_SimpleText_0.pst, _2.si, _2_MockRandom_0.tii, _4_Lucene40WithOrds_0.tib, _4_Lucene40WithOrds_0.tii, _1_Lucene40WithOrds_0.prx, _3_MockRandom_0.frq, _3.fnm, _4_TestBloomFilteredLucene40Postings_0.prx, _2_nrm.cfe, _2_MockRandom_0.tib, _2_nrm.cfs, _4_MockRandom_0.skp, _2_TestBloomFilteredLucene40Postings_0.frq, _2_MockRandom_0.prx, _4_TestBloomFilteredLucene40Postings_0.blm, _2_Lucene40WithOrds_0.frq, _2.fnm, _3.fdx, _2_MockRandom_0.sd, _1.si, _4_TestBloomFilteredLucene40Postings_0.tim, _4_TestBloomFilteredLucene40Postings_0.tip, _0_Lucene40WithOrds_0.prx, _3_Lucene40WithOrds_0.prx, _3_nrm.cfe, _4_MockRandom_0.pos, _2_TestBloomFilteredLucene40Postings_0.prx, _3_Lucene40WithOrds_0.tii, _4.fnm, _4_nrm.cfe, _4_MockRandom_0.tib, _1.fnm, _3_Lucene40WithOrds_0.tib, _4.fdx, _4_MockRandom_0.doc, _4_MockRandom_0.tiv, _2_TestBloomFilteredLucene40Postings_0.tim, _0_TestBloomFilteredLucene40Postings_0.tim, _0_TestBloomFilteredLucene40Postings_0.tip, _0.fnm, _3_MockRandom_0.tib, _1_TestBloomFilteredLucene40Postings_0.frq, _2_TestBloomFilteredLucene40Postings_0.tip, _3_nrm.cfs, _4_Lucene40WithOrds_0.prx, _4_nrm.cfs, _3_MockRandom_0.tiv, _1_MockRandom_0.frq, _0_TestBloomFilteredLucene40Postings_0.prx, _4_Lucene40WithOrds_0.frq, _1_TestBloomFilteredLucene40Postings_0.blm, _1_TestBloomFilteredLucene40Postings_0.tip, _2_Lucene40WithOrds_0.prx, _1_TestBloomFilteredLucene40Postings_0.tim, _0.si, _0_MockRandom_0.tib, _1_nrm.cfs, _1_TestBloomFilteredLucene40Postings_0.prx, _0_nrm.cfs, _3_Lucene40WithOrds_0.frq, _4.fdt, _4.si, _1_nrm.cfe, _3_MockRandom_0.sd, _2_Lucene40WithOrds_0.tii, _1_MockRandom_0.prx, _0_MockRandom_0.sd, _4_MockRandom_0.frq, _0_nrm.cfe, _0_MockRandom_0.tii, _2_MockRandom_0.frq, _0.fdx, _2_Lucene40WithOrds_0.tib, segments_3, _0.fdt]
[junit4:junit4]   2> 20286 T1844 C208 P38332 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 20340 T1844 C208 P38332 oass.SolrIndexSearcher.<init> Opening Searcher@2681c107 main
[junit4:junit4]   2> 20341 T1844 C208 P38332 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 20342 T1848 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2681c107 main{StandardDirectoryReader(segments_3:11 _0(4.0.0.2):C1 _1(4.0.0.2):C10 _2(4.0.0.2):C10 _3(4.0.0.2):C10 _4(4.0.0.2):C1)}
[junit4:junit4]   2> 20343 T1844 C208 P38332 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:38347/solr/collection1/, StdNode: http://127.0.0.1:38342/solr/collection1/, StdNode: http://127.0.0.1:38353/solr/collection1/]
[junit4:junit4]   2> 20344 T1876 C206 P38353 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 20345 T1863 C205 P38347 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 20346 T1856 C209 P38342 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 20770 

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

-1882, 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> 	  35) Thread[id=1837, name=HashSessionScavenger-42, state=TIMED_WAITING, group=TGRP-BasicDistributedZk2Test]
[junit4:junit4]   2> 	        at java.lang.Object.wait(Native Method)
[junit4:junit4]   2> 	        at java.util.TimerThread.mainLoop(Timer.java:552)
[junit4:junit4]   2> 	        at java.util.TimerThread.run(Timer.java:505)
[junit4:junit4]   2> 	  36) Thread[id=1927, name=qtp1037288085-1927, 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> 	  37) Thread[id=1872, name=searcherExecutor-1529-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> NOTE: test params are: codec=Lucene40: {n_f1=PostingsFormat(name=Lucene40WithOrds), foo_b=PostingsFormat(name=SimpleText), foo_d=PostingsFormat(name=MockRandom), foo_f=PostingsFormat(name=SimpleText), n_tl1=PostingsFormat(name=Lucene40WithOrds), n_d1=PostingsFormat(name=TestBloomFilteredLucene40Postings), rnd_b=PostingsFormat(name=MockRandom), intDefault=PostingsFormat(name=Lucene40WithOrds), n_td1=PostingsFormat(name=Lucene40WithOrds), timestamp=PostingsFormat(name=TestBloomFilteredLucene40Postings), id=PostingsFormat(name=MockRandom), range_facet_sl=PostingsFormat(name=MockRandom), range_facet_si=PostingsFormat(name=TestBloomFilteredLucene40Postings), oddField_s=PostingsFormat(name=MockRandom), multiDefault=PostingsFormat(name=TestBloomFilteredLucene40Postings), n_tf1=PostingsFormat(name=TestBloomFilteredLucene40Postings), n_dt1=PostingsFormat(name=Lucene40WithOrds), n_ti1=PostingsFormat(name=MockRandom), range_facet_l=PostingsFormat(name=TestBloomFilteredLucene40Postings), text=PostingsFormat(name=SimpleText), _version_=PostingsFormat(name=Lucene40WithOrds), SubjectTerms_mfacet=PostingsFormat(name=Lucene40WithOrds), a_t=PostingsFormat(name=TestBloomFilteredLucene40Postings), n_tdt1=PostingsFormat(name=Lucene40WithOrds), other_tl1=PostingsFormat(name=Lucene40WithOrds), n_l1=PostingsFormat(name=TestBloomFilteredLucene40Postings), a_si=PostingsFormat(name=Lucene40WithOrds)}, sim=DefaultSimilarity, locale=es_PE, timezone=Greenwich
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Oracle Corporation 1.7.0_06 (64-bit)/cpus=16,threads=45,free=428683864,total=536870912
[junit4:junit4]   2> NOTE: All tests run in this JVM: [SolrPluginUtilsTest, TestLMDirichletSimilarityFactory, TestCharFilters, HighlighterConfigTest, DefaultValueUpdateProcessorTest, TestGroupingSearch, CSVRequestHandlerTest, DistributedSpellCheckComponentTest, CoreAdminHandlerTest, JSONWriterTest, TestSystemIdResolver, RequestHandlersTest, DateMathParserTest, ZkCLITest, TestSolrQueryParser, TermVectorComponentDistributedTest, MBeansHandlerTest, SimpleFacetsTest, DirectUpdateHandlerOptimizeTest, IndexBasedSpellCheckerTest, DateFieldTest, TestLFUCache, TestStressVersions, SuggesterWFSTTest, TestXIncludeConfig, SpellCheckCollatorTest, TestFastOutputStream, LeaderElectionIntegrationTest, SuggesterFSTTest, TestReload, TestPerFieldSimilarity, TestDefaultSimilarityFactory, NotRequiredUniqueKeyTest, CacheHeaderTest, FileBasedSpellCheckerTest, NumericFieldsTest, CoreContainerCoreInitFailuresTest, TestStressReorder, TestFastLRUCache, TestIndexingPerformance, BasicDistributedZkTest, TestJoin, TestSuggestSpellingConverter, TestQueryTypes, ZkControllerTest, SolrRequestParserTest, BadComponentTest, ResourceLoaderTest, UpdateRequestProcessorFactoryTest, MoreLikeThisHandlerTest, MinimalSchemaTest, TestRangeQuery, TestCollationField, TestFiltering, CopyFieldTest, TestSearchPerf, UniqFieldsUpdateProcessorFactoryTest, TestExtendedDismaxParser, AutoCommitTest, BasicZkTest, TestFaceting, WordBreakSolrSpellCheckerTest, DistributedTermsComponentTest, StatsComponentTest, SolrCoreTest, DirectUpdateHandlerTest, TestMultiCoreConfBootstrap, LukeRequestHandlerTest, PeerSyncTest, SortByFunctionTest, SampleTest, TestFunctionQuery, DirectSolrConnectionTest, SpatialFilterTest, CurrencyFieldTest, IndexSchemaTest, BinaryUpdateRequestHandlerTest, DistanceFunctionTest, FieldAnalysisRequestHandlerTest, JsonLoaderTest, IndexSchemaRuntimeFieldTest, FastVectorHighlighterTest, DebugComponentTest, SearchHandlerTest, TestArbitraryIndexDir, LoggingHandlerTest, SolrCmdDistributorTest, PrimitiveFieldTypeTest, SOLR749Test, TestMergePolicyConfig, IndexReaderFactoryTest, TestNumberUtils, TestJmxMonitoredMap, TestConfig, TestPluginEnable, TestIBSimilarityFactory, PluginInfoTest, PrimUtilsTest, SpellingQueryConverterTest, TestLRUCache, RAMDirectoryFactoryTest, SystemInfoHandlerTest, TestUtils, PreAnalyzedFieldTest, ZkNodePropsTest, CircularListTest, TestDocumentBuilder, PathHierarchyTokenizerFactoryTest, BasicDistributedZk2Test]
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZk2Test -Dtests.seed=2EAC51F26CD7A0FB -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_PE -Dtests.timezone=Greenwich -Dtests.file.encoding=ISO-8859-1
[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([2EAC51F26CD7A0FB]:0)
[junit4:junit4] Completed on J0 in 7224.10s, 1 test, 2 errors <<< FAILURES!

[...truncated 7 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/build.xml:29: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build.xml:146: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/module-build.xml:63: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/common-build.xml:1133: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/common-build.xml:810: There were test failures: 229 suites, 927 tests, 1 suite-level error, 1 error, 7 ignored (1 assumption)

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



Mime
View raw message