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 # 389 - Failure
Date Sun, 02 Sep 2012 21:10:06 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-java7/389/

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




Build Log:
[...truncated 7554 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 5 T2596 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/J1/./solrtest-BasicDistributedZk2Test-1346612958952
[junit4:junit4]   2> 7 T2596 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 11 T2597 oazs.ZooKeeperServer.setTickTime tickTime set to 3000
[junit4:junit4]   2> 11 T2597 oazs.NIOServerCnxn$Factory.<init> binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 12 T2597 oazsp.FileTxnSnapLog.save Snapshotting: 0
[junit4:junit4]   2> 108 T2596 oasc.ZkTestServer.run start zk server on port:14835
[junit4:junit4]   2> 108 T2596 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:14835 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@3eca7638
[junit4:junit4]   2> 109 T2602 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:14835
[junit4:junit4]   2> 109 T2596 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 110 T2602 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:14835, initiating session
[junit4:junit4]   2> 111 T2598 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:14836
[junit4:junit4]   2> 111 T2598 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:14836
[junit4:junit4]   2> 112 T2600 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 115 T2600 oazs.NIOServerCnxn.finishSessionInit Established session 0x139886316ef0000 with negotiated timeout 10000 for client /140.211.11.196:14836
[junit4:junit4]   2> 115 T2602 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:14835, sessionid = 0x139886316ef0000, negotiated timeout = 10000
[junit4:junit4]   2> 115 T2603 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3eca7638 name:ZooKeeperConnection Watcher:127.0.0.1:14835 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 116 T2596 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 116 T2596 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 119 T2601 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139886316ef0000
[junit4:junit4]   2> 126 T2603 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 126 T2596 oaz.ZooKeeper.close Session: 0x139886316ef0000 closed
[junit4:junit4]   2> 127 T2598 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:14836 which had sessionid 0x139886316ef0000
[junit4:junit4]   2> 127 T2596 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:14835/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@5da776c8
[junit4:junit4]   2> 128 T2604 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:14835
[junit4:junit4]   2> 128 T2596 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 129 T2604 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:14835, initiating session
[junit4:junit4]   2> 129 T2598 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:14837
[junit4:junit4]   2> 129 T2598 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:14837
[junit4:junit4]   2> 130 T2600 oazs.NIOServerCnxn.finishSessionInit Established session 0x139886316ef0001 with negotiated timeout 10000 for client /140.211.11.196:14837
[junit4:junit4]   2> 130 T2604 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:14835, sessionid = 0x139886316ef0001, negotiated timeout = 10000
[junit4:junit4]   2> 131 T2605 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5da776c8 name:ZooKeeperConnection Watcher:127.0.0.1:14835/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 131 T2596 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 132 T2596 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 135 T2596 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 145 T2596 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 146 T2596 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 153 T2596 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 T2596 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 166 T2596 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> 167 T2596 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 270 T2596 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 T2596 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 273 T2596 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> 274 T2596 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 285 T2596 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 T2596 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 289 T2596 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 T2596 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 292 T2596 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> 296 T2596 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 303 T2596 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> 304 T2596 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 346 T2596 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> 347 T2596 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 349 T2596 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> 350 T2596 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 367 T2601 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139886316ef0001
[junit4:junit4]   2> 368 T2605 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 368 T2596 oaz.ZooKeeper.close Session: 0x139886316ef0001 closed
[junit4:junit4]   2> 369 T2598 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:14837 which had sessionid 0x139886316ef0001
[junit4:junit4]   2> 371 T2596 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 381 T2596 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:14838
[junit4:junit4]   2> 382 T2596 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 382 T2596 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> 383 T2596 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> 422 T2596 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 423 T2596 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 424 T2596 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> 424 T2596 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> 425 T2596 oasc.CoreContainer.<init> New CoreContainer 11565404
[junit4:junit4]   2> 425 T2596 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> 426 T2596 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> 456 T2596 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 469 T2596 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:14835/solr
[junit4:junit4]   2> 470 T2596 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:14835/solr sessionTimeout=8000 watcher=org.apache.solr.common.cloud.ConnectionManager@5e0de6f8
[junit4:junit4]   2> 471 T2615 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:14835
[junit4:junit4]   2> 471 T2596 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 472 T2615 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:14835, initiating session
[junit4:junit4]   2> 472 T2598 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:14839
[junit4:junit4]   2> 472 T2598 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:14839
[junit4:junit4]   2> 473 T2600 oazs.NIOServerCnxn.finishSessionInit Established session 0x139886316ef0002 with negotiated timeout 8000 for client /140.211.11.196:14839
[junit4:junit4]   2> 474 T2615 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:14835, sessionid = 0x139886316ef0002, negotiated timeout = 8000
[junit4:junit4]   2> 474 T2616 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e0de6f8 name:ZooKeeperConnection Watcher:127.0.0.1:14835/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 474 T2596 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 486 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0002 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 487 T2596 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 531 T2596 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:14838_solr
[junit4:junit4]   2> 532 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0002 type:delete cxid:0x7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:14838_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:14838_solr
[junit4:junit4]   2> 534 T2596 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:14838_solr
[junit4:junit4]   2> 552 T2596 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 553 T2596 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 554 T2596 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 554 T2596 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 554 T2596 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 555 T2596 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 555 T2596 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 556 T2596 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 556 T2596 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 557 T2596 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 569 T2596 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 573 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0002 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> 594 T2596 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 596 T2596 oasc.Overseer.start Overseer (id=88251626878337026-127.0.0.1:14838_solr-n_0000000000) starting
[junit4:junit4]   2> 597 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0002 type:create cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 604 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0002 type:create cxid:0x1b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 605 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0002 type:create cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 607 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0002 type:create cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 616 T2618 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 617 T2596 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 619 T2596 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 621 T2617 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 625 T2596 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> 625 T2596 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 626 T2596 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 626 T2596 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 628 T2596 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> 629 T2596 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> 630 T2596 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> 676 T2596 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 735 T2596 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 837 T2596 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 844 T2596 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1491 T2596 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1500 T2596 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1503 T2596 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1512 T2596 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1517 T2596 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1521 T2596 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1522 T2596 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1523 T2596 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-1346612958952/control/data/
[junit4:junit4]   2> 1523 T2596 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@404a6ddc
[junit4:junit4]   2> 1525 T2596 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/control/data/index/
[junit4:junit4]   2> 1525 T2596 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1526 T2596 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/control/data/index forceNew:false
[junit4:junit4]   2> 1533 T2596 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@5f780a9a; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1533 T2596 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 1534 T2596 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 1536 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1537 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 1537 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1538 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 1539 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1539 T2596 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1540 T2596 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1540 T2596 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1541 T2596 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1541 T2596 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 1542 T2596 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 1542 T2596 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1543 T2596 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 1543 T2596 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 1544 T2596 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 1544 T2596 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1545 T2596 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1545 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1546 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1546 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1547 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1548 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1548 T2596 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1549 T2596 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 1549 T2596 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 1552 T2596 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1556 T2596 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 1557 T2596 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> 1560 T2596 oass.SolrIndexSearcher.<init> Opening Searcher@6afdaaa2 main
[junit4:junit4]   2> 1561 T2596 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1562 T2596 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1562 T2596 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 1570 T2596 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 1625 T2619 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6afdaaa2 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1628 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0002 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> 1636 T2596 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 1637 T2596 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:14838/solr shardId:control_shard
[junit4:junit4]   2> 1638 T2596 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/control_shard/election
[junit4:junit4]   2> 1657 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0002 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> 1658 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0002 type:create cxid:0x66 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1666 T2596 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Running the leader process. afterExperiation=false
[junit4:junit4]   2> 2126 T2617 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2127 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0002 type:create cxid:0x6d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 2152 T2616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2668 T2596 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2668 T2596 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:14838/solr/collection1/
[junit4:junit4]   2> 3170 T2596 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/control_shard
[junit4:junit4]   2> 3174 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0002 type:create cxid:0x90 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3664 T2617 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3678 T2616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3697 T2596 oasc.ZkController.register We are http://127.0.0.1:14838/solr/collection1/ and leader is http://127.0.0.1:14838/solr/collection1/
[junit4:junit4]   2> 3697 T2596 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:14838/solr
[junit4:junit4]   2> 3698 T2596 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 3699 T2596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3700 T2596 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 3701 T2596 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 3701 T2596 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 3717 T2596 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 3720 T2596 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:14856
[junit4:junit4]   2> 3720 T2596 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3721 T2596 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> 3721 T2596 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> 3765 T2596 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 3765 T2596 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3766 T2596 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> 3766 T2596 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> 3767 T2596 oasc.CoreContainer.<init> New CoreContainer 1470917224
[junit4:junit4]   2> 3768 T2596 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> 3768 T2596 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> 3800 T2596 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 3815 T2596 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:14835/solr
[junit4:junit4]   2> 3816 T2596 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:14835/solr sessionTimeout=8000 watcher=org.apache.solr.common.cloud.ConnectionManager@7766aa89
[junit4:junit4]   2> 3817 T2629 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:14835
[junit4:junit4]   2> 3817 T2596 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3818 T2629 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:14835, initiating session
[junit4:junit4]   2> 3818 T2598 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:14857
[junit4:junit4]   2> 3819 T2598 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:14857
[junit4:junit4]   2> 3820 T2600 oazs.NIOServerCnxn.finishSessionInit Established session 0x139886316ef0003 with negotiated timeout 8000 for client /140.211.11.196:14857
[junit4:junit4]   2> 3820 T2629 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:14835, sessionid = 0x139886316ef0003, negotiated timeout = 8000
[junit4:junit4]   2> 3820 T2630 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7766aa89 name:ZooKeeperConnection Watcher:127.0.0.1:14835/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3821 T2596 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3822 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0003 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3823 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0003 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3831 T2596 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:14856_solr
[junit4:junit4]   2> 3831 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0003 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:14856_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:14856_solr
[junit4:junit4]   2> 3832 T2596 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:14856_solr
[junit4:junit4]   2> 3835 T2616 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 3835 T2596 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 3836 T2596 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 3836 T2596 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 3837 T2596 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 3837 T2596 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 3838 T2596 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 3838 T2596 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 3839 T2596 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 3839 T2596 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 3840 T2596 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 3852 T2596 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3857 T2596 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> 3858 T2596 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 3859 T2596 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 3859 T2596 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 3860 T2596 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> 3862 T2596 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> 3863 T2596 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> 3914 T2596 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 3984 T2596 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 4085 T2596 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 4092 T2596 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 4182 T2617 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4195 T2616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4195 T2630 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4666 T2596 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 4677 T2596 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 4681 T2596 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 4692 T2596 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 4697 T2596 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 4701 T2596 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 4702 T2596 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 4703 T2596 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-1346612958952/jetty1/
[junit4:junit4]   2> 4704 T2596 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@404a6ddc
[junit4:junit4]   2> 4705 T2596 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty1/index/
[junit4:junit4]   2> 4706 T2596 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 4707 T2596 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty1/index forceNew:false
[junit4:junit4]   2> 4714 T2596 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@228c4dab; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 4715 T2596 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 4716 T2596 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 4719 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 4720 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 4720 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 4721 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 4722 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 4722 T2596 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 4723 T2596 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 4724 T2596 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 4725 T2596 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 4726 T2596 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 4727 T2596 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 4727 T2596 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 4728 T2596 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 4729 T2596 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 4729 T2596 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 4730 T2596 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 4731 T2596 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4732 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4732 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4733 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4734 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4735 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4735 T2596 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4736 T2596 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 4737 T2596 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 4741 T2596 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 4745 T2596 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 4746 T2596 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> 4749 T2596 oass.SolrIndexSearcher.<init> Opening Searcher@6092c80d main
[junit4:junit4]   2> 4750 T2596 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 4750 T2596 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 4751 T2596 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 4756 T2596 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 4802 T2631 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6092c80d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 5199 T2617 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5212 T2616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5212 T2630 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5307 T2596 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 5307 T2596 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:14856/solr shardId:shard1
[junit4:junit4]   2> 5308 T2596 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 5385 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0003 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> 5412 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0003 type:create cxid:0x44 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5453 T2596 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Running the leader process. afterExperiation=false
[junit4:junit4]   2> 5454 T2596 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 5454 T2596 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:14856/solr/collection1/
[junit4:junit4]   2> 5715 T2617 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5746 T2616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5746 T2630 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5955 T2596 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 5980 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0003 type:create cxid:0x4e zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6250 T2617 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6265 T2616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6265 T2630 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6297 T2596 oasc.ZkController.register We are http://127.0.0.1:14856/solr/collection1/ and leader is http://127.0.0.1:14856/solr/collection1/
[junit4:junit4]   2> 6297 T2596 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:14856/solr
[junit4:junit4]   2> 6298 T2596 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 6299 T2596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6300 T2596 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 6301 T2596 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 6301 T2596 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 6317 T2596 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 6320 T2596 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:14860
[junit4:junit4]   2> 6321 T2596 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 6321 T2596 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> 6322 T2596 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> 6365 T2596 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 6366 T2596 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 6367 T2596 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> 6367 T2596 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> 6368 T2596 oasc.CoreContainer.<init> New CoreContainer 528596343
[junit4:junit4]   2> 6368 T2596 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> 6369 T2596 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> 6401 T2596 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 6414 T2596 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:14835/solr
[junit4:junit4]   2> 6415 T2596 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:14835/solr sessionTimeout=8000 watcher=org.apache.solr.common.cloud.ConnectionManager@aab8992
[junit4:junit4]   2> 6416 T2641 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:14835
[junit4:junit4]   2> 6416 T2596 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 6417 T2641 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:14835, initiating session
[junit4:junit4]   2> 6417 T2598 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:14861
[junit4:junit4]   2> 6418 T2598 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:14861
[junit4:junit4]   2> 6419 T2600 oazs.NIOServerCnxn.finishSessionInit Established session 0x139886316ef0004 with negotiated timeout 8000 for client /140.211.11.196:14861
[junit4:junit4]   2> 6419 T2641 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:14835, sessionid = 0x139886316ef0004, negotiated timeout = 8000
[junit4:junit4]   2> 6420 T2642 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@aab8992 name:ZooKeeperConnection Watcher:127.0.0.1:14835/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 6420 T2596 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 6421 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0004 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6430 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0004 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6431 T2596 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:14860_solr
[junit4:junit4]   2> 6431 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0004 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:14860_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:14860_solr
[junit4:junit4]   2> 6432 T2596 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:14860_solr
[junit4:junit4]   2> 6441 T2616 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 6441 T2630 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 6442 T2596 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 6443 T2596 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 6443 T2596 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 6444 T2596 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 6444 T2596 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 6445 T2596 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 6445 T2596 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 6446 T2596 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 6446 T2596 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 6447 T2596 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 6459 T2596 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 6464 T2596 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> 6465 T2596 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 6466 T2596 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 6466 T2596 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 6467 T2596 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> 6469 T2596 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> 6469 T2596 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> 6520 T2596 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 6609 T2596 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 6710 T2596 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 6716 T2596 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 6768 T2617 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6783 T2616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6783 T2642 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6783 T2630 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7271 T2596 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 7279 T2596 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 7282 T2596 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 7289 T2596 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 7293 T2596 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 7296 T2596 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 7297 T2596 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 7298 T2596 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-1346612958952/jetty2/
[junit4:junit4]   2> 7298 T2596 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@404a6ddc
[junit4:junit4]   2> 7299 T2596 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty2/index/
[junit4:junit4]   2> 7300 T2596 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 7301 T2596 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty2/index forceNew:false
[junit4:junit4]   2> 7306 T2596 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2daf79e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 7306 T2596 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 7307 T2596 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 7309 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 7310 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 7310 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 7310 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 7311 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 7311 T2596 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 7312 T2596 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 7312 T2596 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 7313 T2596 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 7314 T2596 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 7314 T2596 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 7315 T2596 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 7315 T2596 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 7316 T2596 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 7316 T2596 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 7317 T2596 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 7317 T2596 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7318 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7318 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7319 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7319 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7320 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7320 T2596 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7321 T2596 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 7321 T2596 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 7324 T2596 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 7327 T2596 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 7328 T2596 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> 7331 T2596 oass.SolrIndexSearcher.<init> Opening Searcher@1a151923 main
[junit4:junit4]   2> 7332 T2596 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 7333 T2596 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 7333 T2596 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 7339 T2596 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 7398 T2643 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1a151923 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 7787 T2617 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7800 T2630 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7800 T2616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7800 T2642 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7906 T2596 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 7906 T2596 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:14860/solr shardId:shard2
[junit4:junit4]   2> 7907 T2596 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 7911 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0004 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> 7911 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0004 type:create cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7912 T2596 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Running the leader process. afterExperiation=false
[junit4:junit4]   2> 7913 T2596 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 7913 T2596 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:14860/solr/collection1/
[junit4:junit4]   2> 8303 T2617 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8316 T2616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8316 T2642 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8316 T2630 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8415 T2596 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 8417 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0004 type:create cxid:0x4c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8819 T2617 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8828 T2616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8828 T2630 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8828 T2642 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8878 T2596 oasc.ZkController.register We are http://127.0.0.1:14860/solr/collection1/ and leader is http://127.0.0.1:14860/solr/collection1/
[junit4:junit4]   2> 8878 T2596 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:14860/solr
[junit4:junit4]   2> 8879 T2596 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 8881 T2596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8882 T2596 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 8882 T2596 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 8883 T2596 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 8899 T2596 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 8902 T2596 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:14867
[junit4:junit4]   2> 8903 T2596 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8904 T2596 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> 8904 T2596 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> 8954 T2596 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 8954 T2596 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8955 T2596 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> 8955 T2596 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> 8956 T2596 oasc.CoreContainer.<init> New CoreContainer 2102205853
[junit4:junit4]   2> 8957 T2596 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> 8957 T2596 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> 8992 T2596 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 9007 T2596 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:14835/solr
[junit4:junit4]   2> 9007 T2596 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:14835/solr sessionTimeout=8000 watcher=org.apache.solr.common.cloud.ConnectionManager@61d832a9
[junit4:junit4]   2> 9008 T2653 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:14835
[junit4:junit4]   2> 9008 T2596 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 9009 T2653 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:14835, initiating session
[junit4:junit4]   2> 9010 T2598 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:14868
[junit4:junit4]   2> 9010 T2598 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:14868
[junit4:junit4]   2> 9012 T2600 oazs.NIOServerCnxn.finishSessionInit Established session 0x139886316ef0005 with negotiated timeout 8000 for client /140.211.11.196:14868
[junit4:junit4]   2> 9012 T2653 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:14835, sessionid = 0x139886316ef0005, negotiated timeout = 8000
[junit4:junit4]   2> 9012 T2654 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@61d832a9 name:ZooKeeperConnection Watcher:127.0.0.1:14835/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 9013 T2596 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 9014 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0005 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 9022 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0005 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 9025 T2596 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:14867_solr
[junit4:junit4]   2> 9025 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0005 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:14867_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:14867_solr
[junit4:junit4]   2> 9026 T2596 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:14867_solr
[junit4:junit4]   2> 9036 T2630 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 9036 T2642 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 9036 T2616 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 9037 T2596 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 9037 T2596 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 9038 T2596 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 9038 T2596 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 9039 T2596 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 9039 T2596 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 9040 T2596 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 9040 T2596 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 9041 T2596 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 9041 T2596 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 9053 T2596 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9060 T2596 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> 9060 T2596 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 9061 T2596 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 9061 T2596 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 9062 T2596 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> 9064 T2596 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> 9065 T2596 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> 9119 T2596 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 9190 T2596 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 9291 T2596 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 9297 T2596 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 9332 T2617 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9339 T2616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9339 T2642 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9339 T2630 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9339 T2654 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9908 T2596 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 9919 T2596 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 9923 T2596 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 9933 T2596 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 9938 T2596 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 9942 T2596 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 9943 T2596 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 9944 T2596 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-1346612958952/jetty3/
[junit4:junit4]   2> 9945 T2596 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@404a6ddc
[junit4:junit4]   2> 9946 T2596 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty3/index/
[junit4:junit4]   2> 9947 T2596 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 9948 T2596 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty3/index forceNew:false
[junit4:junit4]   2> 9955 T2596 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@744f5a31; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9956 T2596 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 9957 T2596 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 9960 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 9960 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 9961 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 9962 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 9963 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 9963 T2596 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 9964 T2596 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 9965 T2596 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 9965 T2596 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 9966 T2596 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 9967 T2596 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 9968 T2596 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 9969 T2596 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 9969 T2596 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 9970 T2596 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 9971 T2596 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 9971 T2596 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9972 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9973 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9974 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9974 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9975 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9976 T2596 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9977 T2596 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 9978 T2596 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 9981 T2596 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 9986 T2596 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 9987 T2596 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> 9991 T2596 oass.SolrIndexSearcher.<init> Opening Searcher@27fc5455 main
[junit4:junit4]   2> 9992 T2596 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 9993 T2596 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 9994 T2596 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 10012 T2596 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 10060 T2655 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@27fc5455 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 10352 T2617 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10399 T2616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10399 T2654 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10399 T2642 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10399 T2630 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10570 T2596 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 10571 T2596 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:14867/solr shardId:shard1
[junit4:junit4]   2> 10602 T2596 oasc.ZkController.register We are http://127.0.0.1:14867/solr/collection1/ and leader is http://127.0.0.1:14856/solr/collection1/
[junit4:junit4]   2> 10603 T2596 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:14867/solr
[junit4:junit4]   2> 10603 T2596 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> ASYNC  NEW_CORE C169 name=collection1 org.apache.solr.core.SolrCore@58c0caa url=http://127.0.0.1:14867/solr/collection1 node=127.0.0.1:14867_solr
[junit4:junit4]   2> 10605 T2656 C169 P14867 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 10606 T2656 C169 P14867 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 10605 T2596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10622 T2656 C169 P14867 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 10622 T2596 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 10623 T2596 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 10624 T2596 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 10642 T2596 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 10645 T2596 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:14870
[junit4:junit4]   2> 10645 T2596 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 10646 T2596 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> 10646 T2596 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> 10696 T2596 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 10697 T2596 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 10697 T2596 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> 10698 T2596 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> 10698 T2596 oasc.CoreContainer.<init> New CoreContainer 27012866
[junit4:junit4]   2> 10699 T2596 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> 10699 T2596 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> 10739 T2596 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 10754 T2596 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:14835/solr
[junit4:junit4]   2> 10755 T2596 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:14835/solr sessionTimeout=8000 watcher=org.apache.solr.common.cloud.ConnectionManager@2bdeccfe
[junit4:junit4]   2> 10756 T2666 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:14835
[junit4:junit4]   2> 10756 T2596 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 10757 T2666 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:14835, initiating session
[junit4:junit4]   2> 10757 T2598 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:14873
[junit4:junit4]   2> 10757 T2598 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:14873
[junit4:junit4]   2> 10759 T2600 oazs.NIOServerCnxn.finishSessionInit Established session 0x139886316ef0006 with negotiated timeout 8000 for client /140.211.11.196:14873
[junit4:junit4]   2> 10759 T2666 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:14835, sessionid = 0x139886316ef0006, negotiated timeout = 8000
[junit4:junit4]   2> 10760 T2667 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2bdeccfe name:ZooKeeperConnection Watcher:127.0.0.1:14835/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 10760 T2596 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 10761 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0006 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 10763 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0006 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 10764 T2596 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:14870_solr
[junit4:junit4]   2> 10765 T2601 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139886316ef0006 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:14870_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:14870_solr
[junit4:junit4]   2> 10773 T2596 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:14870_solr
[junit4:junit4]   2> 10776 T2616 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 10776 T2642 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 10776 T2654 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 10776 T2630 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 10776 T2596 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 10777 T2596 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 10777 T2596 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 10778 T2596 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 10779 T2596 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 10779 T2596 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 10780 T2596 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 10781 T2596 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 10782 T2596 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 10782 T2596 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 10797 T2596 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 10804 T2596 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> 10805 T2596 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 10806 T2596 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 10806 T2596 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 10807 T2596 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> 10809 T2596 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> 10810 T2596 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> 10862 T2596 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 10930 T2596 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 10933 T2617 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10946 T2642 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10946 T2654 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10946 T2616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10946 T2630 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11031 T2667 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11031 T2596 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 11038 T2596 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 11648 T2596 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 11659 T2596 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 11664 T2596 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 11674 T2596 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 11680 T2596 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 11684 T2596 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 11685 T2596 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 11687 T2596 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-1346612958952/jetty4/
[junit4:junit4]   2> 11687 T2596 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@404a6ddc
[junit4:junit4]   2> 11689 T2596 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty4/index/
[junit4:junit4]   2> 11690 T2596 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 11691 T2596 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty4/index forceNew:false
[junit4:junit4]   2> 11724 T2596 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@33624433; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 11725 T2596 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 11726 T2596 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 11729 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 11730 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 11730 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 11731 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 11732 T2596 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 11732 T2596 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 11733 T2596 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 11734 T2596 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 11735 T2596 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 11736 T2596 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 11736 T2596 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 11737 T2596 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 11738 T2596 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 11738 T2596 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 11739 T2596 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 11740 T2596 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 11741 T2596 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11741 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11742 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11743 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11744 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11745 T2596 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11745 T2596 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11746 T2596 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 11747 T2596 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 11750 T2596 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 11755 T2596 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 11756 T2596 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> 11760 T2596 oass.SolrIndexSearcher.<init> Opening Searcher@2700f35b main
[junit4:junit4]   2> 11761 T2596 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 11762 T2596 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 11762 T2596 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 11776 T2596 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 11846 T2668 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2700f35b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 11950 T2617 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11953 T2616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11953 T2630 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11953 T2642 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11953 T2667 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11953 T2654 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12354 T2596 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 12354 T2596 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:14870/solr shardId:shard2
[junit4:junit4]   2> 12358 T2596 oasc.ZkController.register We are http://127.0.0.1:14870/solr/collection1/ and leader is http://127.0.0.1:14860/solr/collection1/
[junit4:junit4]   2> 12358 T2596 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:14870/solr
[junit4:junit4]   2> 12359 T2596 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> ASYNC  NEW_CORE C170 name=collection1 org.apache.solr.core.SolrCore@45677f9b url=http://127.0.0.1:14870/solr/collection1 node=127.0.0.1:14870_solr
[junit4:junit4]   2> 12361 T2669 C170 P14870 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 12361 T2669 C170 P14870 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 12361 T2596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12363 T2669 C170 P14870 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 12363 T2596 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 12363 T2596 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 12364 T2596 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 12380 T2596 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:14835/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@3abd18dc
[junit4:junit4]   2> 12382 T2670 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:14835
[junit4:junit4]   2> 12382 T2596 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12383 T2670 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:14835, initiating session
[junit4:junit4]   2> 12383 T2598 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:14876
[junit4:junit4]   2> 12384 T2598 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:14876
[junit4:junit4]   2> 12385 T2600 oazs.NIOServerCnxn.finishSessionInit Established session 0x139886316ef0007 with negotiated timeout 10000 for client /140.211.11.196:14876
[junit4:junit4]   2> 12385 T2670 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:14835, sessionid = 0x139886316ef0007, negotiated timeout = 10000
[junit4:junit4]   2> 12385 T2671 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3abd18dc name:ZooKeeperConnection Watcher:127.0.0.1:14835/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12386 T2596 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12386 T2596 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 12388 T2596 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:true
[junit4:junit4]   2> 12389 T2596 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 12402 T2596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> ASYNC  NEW_CORE C171 name=collection1 org.apache.solr.core.SolrCore@4d03a0d7 url=http://127.0.0.1:14838/solr/collection1 node=127.0.0.1:14838_solr
[junit4:junit4]   2> 12417 T2608 C171 P14838 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@5f780a9a; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 12418 T2608 C171 P14838 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 12422 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[1 (1412026043055734784)]} 0 9
[junit4:junit4]   2> 12423 T2596 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:14835/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@217800a9
[junit4:junit4]   2> 12424 T2672 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:14835
[junit4:junit4]   2> 12424 T2596 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12425 T2672 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:14835, initiating session
[junit4:junit4]   2> 12425 T2598 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:14880
[junit4:junit4]   2> 12426 T2598 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:14880
[junit4:junit4]   2> 12427 T2600 oazs.NIOServerCnxn.finishSessionInit Established session 0x139886316ef0008 with negotiated timeout 10000 for client /140.211.11.196:14880
[junit4:junit4]   2> 12427 T2672 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:14835, sessionid = 0x139886316ef0008, negotiated timeout = 10000
[junit4:junit4]   2> 12427 T2673 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@217800a9 name:ZooKeeperConnection Watcher:127.0.0.1:14835/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12427 T2596 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12428 T2596 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> ASYNC  NEW_CORE C172 name=collection1 org.apache.solr.core.SolrCore@2e32fe6d url=http://127.0.0.1:14856/solr/collection1 node=127.0.0.1:14856_solr
[junit4:junit4]   2> 12447 T2623 C172 P14856 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@228c4dab; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 12448 T2623 C172 P14856 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 12455 T2617 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C169_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:14867_solr, base_url=http://127.0.0.1:14867/solr}
[junit4:junit4]   2> 12464 T2646 C169 P14867 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@744f5a31; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 12465 T2646 C169 P14867 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 12468 T2654 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12468 T2642 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12468 T2667 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12468 T2671 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12468 T2673 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12468 T2630 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12468 T2616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12470 T2646 C169 P14867 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14856/solr/collection1/&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 12470 T2623 C172 P14856 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=28 
[junit4:junit4]   2> ASYNC  NEW_CORE C173 name=collection1 org.apache.solr.core.SolrCore@791edddb url=http://127.0.0.1:14860/solr/collection1 node=127.0.0.1:14860_solr
[junit4:junit4]   2> 12471 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[1]} 0 34
[junit4:junit4]   2> 12471 T2596 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):360
[junit4:junit4]   2> 12472 T2596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13474 T2596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14476 T2596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15478 T2596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16480 T2596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 17482 T2596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 17644 T2656 C169 P14867 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:14856/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 17644 T2656 C169 P14867 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:14867/solr START replicas=[http://127.0.0.1:14856/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 17645 T2656 C169 P14867 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 17645 T2656 C169 P14867 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 17645 T2656 C169 P14867 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 17646 T2656 C169 P14867 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty3/tlog/tlog.0000000000000000000 refcount=1}}
[junit4:junit4]   2> 17646 T2656 C169 P14867 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:14856/solr/collection1/. core=collection1
[junit4:junit4]   2> 17646 T2656 C169 P14867 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 17647 T2624 C172 P14856 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 17661 T2625 C172 P14856 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 17788 T2625 C172 P14856 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@228c4dab; 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@228c4dab; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Block_0.pos, _0_Block_0.tip, _0_MockSep_0.pos, _0_Block_0.tim, _0_MockFixedIntBlock_0.tib, _0_Pulsing40_0.prx, _0_Pulsing40_0.frq, _0_MockFixedIntBlock_0.skp, _0_MockFixedIntBlock_0.pyl, _0_MockSep_0.skp, _0_MockFixedIntBlock_0.tii, _0_Pulsing40_0.tip, _0_MockSep_0.doc, _0.si, _0.fnm, _0_Block_0.doc, _0_Pulsing40_0.tim, _0_MockFixedIntBlock_0.pos, _0_nrm.cfs, _0_MockFixedIntBlock_0.frq, _0_MockSep_0.tib, _0_MockFixedIntBlock_0.doc, _0_nrm.cfe, _0_MockSep_0.frq, segments_2, _0.fdx, _0_MockSep_0.tii, _0_MockSep_0.pyl, _0.fdt]
[junit4:junit4]   2> 17789 T2625 C172 P14856 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 17807 T2625 C172 P14856 oass.SolrIndexSearcher.<init> Opening Searcher@c426e67 main
[junit4:junit4]   2> 17807 T2625 C172 P14856 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 17809 T2631 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c426e67 main{StandardDirectoryReader(segments_2:3 _0(4.0.0.2):C1)}
[junit4:junit4]   2> 17810 T2625 C172 P14856 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 149
[junit4:junit4]   2> 17811 T2656 C169 P14867 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 17811 T2656 C169 P14867 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 17814 T2626 C172 P14856 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 17814 T2626 C172 P14856 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=2 
[junit4:junit4]   2> 17815 T2656 C169 P14867 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 17815 T2656 C169 P14867 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 17815 T2656 C169 P14867 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 17820 T2626 C172 P14856 REQ /replication {command=filelist&generation=2&wt=javabin&qt=/replication&version=2} status=0 QTime=3 
[junit4:junit4]   2> 17821 T2656 C169 P14867 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 29
[junit4:junit4]   2> 17830 T2656 C169 P14867 oash.SnapPuller.fetchLatestIndex Starting download to ./org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty3/index.20120902200936767 fullCopy=true
[junit4:junit4]   2> 17833 T2626 C172 P14856 REQ /replication {file=_0_Block_0.tip&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17838 T2626 C172 P14856 REQ /replication {file=_0_Block_0.pos&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17842 T2626 C172 P14856 REQ /replication {file=_0_MockSep_0.pos&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17846 T2626 C172 P14856 REQ /replication {file=_0_Block_0.tim&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17850 T2626 C172 P14856 REQ /replication {file=_0_Pulsing40_0.prx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17854 T2626 C172 P14856 REQ /replication {file=_0_MockFixedIntBlock_0.tib&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17858 T2626 C172 P14856 REQ /replication {file=_0_Pulsing40_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17862 T2626 C172 P14856 REQ /replication {file=_0_MockFixedIntBlock_0.pyl&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17863 T2656 C169 P14867 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockFixedIntBlock_0.pyl, lastmodified=1346612976000, size=0}
[junit4:junit4]   2> 17866 T2626 C172 P14856 REQ /replication {file=_0_MockFixedIntBlock_0.skp&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17867 T2656 C169 P14867 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockFixedIntBlock_0.skp, lastmodified=1346612976000, size=0}
[junit4:junit4]   2> 17870 T2626 C172 P14856 REQ /replication {file=_0_MockSep_0.skp&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17871 T2656 C169 P14867 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockSep_0.skp, lastmodified=1346612976000, size=0}
[junit4:junit4]   2> 17874 T2626 C172 P14856 REQ /replication {file=_0_MockFixedIntBlock_0.tii&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17878 T2626 C172 P14856 REQ /replication {file=_0_Pulsing40_0.tip&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17882 T2626 C172 P14856 REQ /replication {file=_0.si&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17887 T2626 C172 P14856 REQ /replication {file=_0_MockSep_0.doc&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 17891 T2626 C172 P14856 REQ /replication {file=_0_Pulsing40_0.tim&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17895 T2626 C172 P14856 REQ /replication {file=_0_Block_0.doc&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17899 T2626 C172 P14856 REQ /replication {file=_0.fnm&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17903 T2626 C172 P14856 REQ /replication {file=_0_MockFixedIntBlock_0.pos&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17907 T2626 C172 P14856 REQ /replication {file=_0_nrm.cfs&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17911 T2626 C172 P14856 REQ /replication {file=_0_MockSep_0.tib&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17915 T2626 C172 P14856 REQ /replication {file=_0_MockFixedIntBlock_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17919 T2626 C172 P14856 REQ /replication {file=_0_MockFixedIntBlock_0.doc&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17923 T2626 C172 P14856 REQ /replication {file=_0_nrm.cfe&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17927 T2626 C172 P14856 REQ /replication {file=segments_2&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17931 T2626 C172 P14856 REQ /replication {file=_0_MockSep_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17935 T2626 C172 P14856 REQ /replication {file=_0.fdx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17939 T2626 C172 P14856 REQ /replication {file=_0_MockSep_0.tii&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17943 T2626 C172 P14856 REQ /replication {file=_0_MockSep_0.pyl&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17970 T2656 C169 P14867 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockSep_0.pyl, lastmodified=1346612976000, size=0}
[junit4:junit4]   2> 17974 T2626 C172 P14856 REQ /replication {file=_0.fdt&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 17976 T2656 C169 P14867 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 17977 T2656 C169 P14867 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20120902200936767
[junit4:junit4]   2> 17979 T2656 C169 P14867 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 17979 T2656 C169 P14867 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 17979 T2656 C169 P14867 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 17984 T2656 C169 P14867 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=./org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty3/index/ new=./org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty3/index.20120902200936767
[junit4:junit4]   2> 17984 T2656 C169 P14867 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty3/index.20120902200936767 forceNew:true
[junit4:junit4]   2> 17997 T2656 C169 P14867 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty3/index.20120902200936767 lockFactory=org.apache.lucene.store.NativeFSLockFactory@75bf3fd4; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Block_0.tip, _0_Block_0.pos, _0_MockSep_0.pos, _0_Block_0.tim, _0_Pulsing40_0.prx, _0_MockFixedIntBlock_0.tib, _0_Pulsing40_0.frq, _0_MockFixedIntBlock_0.pyl, _0_MockFixedIntBlock_0.skp, _0_MockSep_0.skp, _0_MockFixedIntBlock_0.tii, _0_Pulsing40_0.tip, _0_MockSep_0.doc, _0.si, _0.fnm, _0_Block_0.doc, _0_Pulsing40_0.tim, _0_MockFixedIntBlock_0.pos, _0_nrm.cfs, _0_MockFixedIntBlock_0.frq, _0_MockSep_0.tib, _0_MockFixedIntBlock_0.doc, _0_nrm.cfe, _0_MockSep_0.frq, segments_2, _0.fdx, _0_MockSep_0.tii, _0_MockSep_0.pyl, _0.fdt]
[junit4:junit4]   2> 17998 T2656 C169 P14867 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 17998 T2656 C169 P14867 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 18003 T2656 C169 P14867 oass.SolrIndexSearcher.<init> Opening Searcher@3b4ec713 main
[junit4:junit4]   2> 18005 T2655 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3b4ec713 main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 18005 T2655 oasc.CachingDirectoryFactory.close Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty3/index
[junit4:junit4]   2> 18005 T2655 oash.SnapPuller$2.onClose removing old index directory ./org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty3/index
[junit4:junit4]   2> 18007 T2656 C169 P14867 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 18009 T2656 C169 P14867 oass.SolrIndexSearcher.<init> Opening Searcher@4ff2d2c9 main
[junit4:junit4]   2> 18009 T2656 C169 P14867 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18010 T2655 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4ff2d2c9 main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 18011 T2656 C169 P14867 oasc.RecoveryStrategy.replay Replaying buffered documents. core=collection1
[junit4:junit4]   2> 18011 T2678 C169 P14867 oasu.UpdateLog$LogReplayer.doReplay WARNING Starting log replay tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty3/tlog/tlog.0000000000000000000 refcount=2} active=true starting pos=434
[junit4:junit4]   2> 18012 T2678 C169 P14867 oasu.DirectUpdateHandler2.commit start commit{flags=2,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 18014 T2678 C169 P14867 oass.SolrIndexSearcher.<init> Opening Searcher@19d2bc3a main
[junit4:junit4]   2> 18015 T2678 C169 P14867 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18016 T2655 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@19d2bc3a main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 18016 T2678 C169 P14867 oasu.UpdateLog$LogReplayer.run WARNING Log replay finished. recoveryInfo=RecoveryInfo{adds=0 deletes=0 deleteByQuery=0 errors=0 positionOfStart=434}
[junit4:junit4]   2> 18017 T2656 C169 P14867 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 18018 T2656 C169 P14867 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 18483 T2617 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18485 T2596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18497 T2654 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 18497 T2616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 18497 T2667 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 18497 T2642 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 18497 T2630 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 18497 T2671 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 18497 T2673 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2>  C170_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:14870_solr, base_url=http://127.0.0.1:14870/solr}
[junit4:junit4]   2> 19384 T2669 C170 P14870 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:14860/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 19384 T2669 C170 P14870 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:14870/solr START replicas=[http://127.0.0.1:14860/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 19385 T2669 C170 P14870 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 19385 T2669 C170 P14870 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 19385 T2669 C170 P14870 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 19385 T2669 C170 P14870 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 19386 T2669 C170 P14870 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:14860/solr/collection1/. core=collection1
[junit4:junit4]   2> 19386 T2669 C170 P14870 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 19387 T2636 C173 P14860 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 19404 T2637 C173 P14860 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 19409 T2637 C173 P14860 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2daf79e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 19410 T2637 C173 P14860 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 19411 T2637 C173 P14860 oass.SolrIndexSearcher.<init> Opening Searcher@58a5b202 main
[junit4:junit4]   2> 19412 T2637 C173 P14860 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 19413 T2643 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@58a5b202 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 19414 T2637 C173 P14860 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 10
[junit4:junit4]   2> 19415 T2669 C170 P14870 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 19415 T2669 C170 P14870 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 19417 T2638 C173 P14860 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 19417 T2638 C173 P14860 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 19423 T2669 C170 P14870 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@33624433; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 19424 T2669 C170 P14870 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 19425 T2669 C170 P14870 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 19430 T2669 C170 P14870 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@33624433; 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@33624433; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 19430 T2669 C170 P14870 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 19435 T2669 C170 P14870 oass.SolrIndexSearcher.<init> Opening Searcher@3ec0eb6e main
[junit4:junit4]   2> 19436 T2669 C170 P14870 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 19437 T2668 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3ec0eb6e main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 19438 T2669 C170 P14870 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 19438 T2669 C170 P14870 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 19440 T2669 C170 P14870 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 19486 T2596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19501 T2617 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19513 T2616 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 19513 T2673 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 19513 T2671 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 19513 T2667 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 19513 T2642 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 19513 T2654 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 19514 T2630 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 20488 T2596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20491 T2608 C171 P14838 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 20608 T2608 C171 P14838 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@5f780a9a; 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@5f780a9a; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Block_0.pos, _0_Block_0.tip, _0_MockSep_0.pos, _0_Block_0.tim, _0_MockFixedIntBlock_0.tib, _0_Pulsing40_0.prx, _0_Pulsing40_0.frq, _0_MockFixedIntBlock_0.skp, _0_MockFixedIntBlock_0.pyl, _0_MockSep_0.skp, _0_MockFixedIntBlock_0.tii, _0_Pulsing40_0.tip, _0_MockSep_0.doc, _0.si, _0.fnm, _0_Block_0.doc, _0_Pulsing40_0.tim, _0_MockFixedIntBlock_0.pos, _0_nrm.cfs, _0_MockFixedIntBlock_0.frq, _0_MockSep_0.tib, _0_MockFixedIntBlock_0.doc, _0_nrm.cfe, _0_MockSep_0.frq, segments_2, _0.fdx, _0_MockSep_0.tii, _0_MockSep_0.pyl, _0.fdt]
[junit4:junit4]   2> 20609 T2608 C171 P14838 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 20627 T2608 C171 P14838 oass.SolrIndexSearcher.<init> Opening Searcher@33c54850 main
[junit4:junit4]   2> 20628 T2608 C171 P14838 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 20629 T2619 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@33c54850 main{StandardDirectoryReader(segments_2:3 _0(4.0.0.2):C1)}
[junit4:junit4]   2> 20631 T2608 C171 P14838 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 140
[junit4:junit4]   2> 20633 T2627 C172 P14856 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 20644 T2627 C172 P14856 oass.SolrIndexSearcher.<init> Opening Searcher@5b1bbfcc main
[junit4:junit4]   2> 20645 T2627 C172 P14856 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 20646 T2631 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5b1bbfcc main{StandardDirectoryReader(segments_2:3 _0(4.0.0.2):C1)}
[junit4:junit4]   2> 20647 T2627 C172 P14856 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:14867/solr/collection1/, StdNode: http://127.0.0.1:14860/solr/collection1/, StdNode: http://127.0.0.1:14870/solr/collection1/]
[junit4:junit4]   2> 20649 T2639 C173 P14860 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2>  C169_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:14867_solr, base_url=http://127.0.0.1:14867/solr}
[junit4:junit4]   2> 20651 T2646 C169 P14867 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 20653 T2646 C169 P14867 oass.SolrIndexSearcher.<init> Opening Searcher@51448a7 main
[junit4:junit4]   2> 20653 T2646 C169 P14867 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 20653 T2639 C173 P14860 oass.SolrIndexSearcher.<init> Opening Searcher@cd3448c main
[junit4:junit4]   2> 20654 T2639 C173 P14860 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 20654 T2655 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@51448a7 main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 20655 T2646 C169 P14867 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&softCommit=false&version=2} {commit=} 0 5
[junit4:junit4]   2> 20655 T2643 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@cd3448c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 20656 T2639 C173 P14860 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&softCommit=false&version=2} {commit=} 0 7
[junit4:junit4]   2>  C170_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:14870_solr, base_url=http://127.0.0.1:14870/solr}
[junit4:junit4]   2> 20657 T2659 C170 P14870 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 20661 T2659 C170 P14870 oass.SolrIndexSearcher.<init> Opening Searcher@467af482 main
[junit4:junit4]   2> 20662 T2659 C170 P14870 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 20663 T2668 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@467af482 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 20664 T2659 C170 P14870 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&softCommit=false&version=2} {commit=} 0 7
[junit4:junit4]   2> 20664 T2627 C172 P14856 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 31
[junit4:junit4]   2> 20670 T2609 C171 P14838 REQ /select {fl=id,score&shard.url=127.0.0.1:14838/solr/collection1/&NOW=1346612979613&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 20673 T2609 C171 P14838 REQ /select {shard.url=127.0.0.1:14838/solr/collection1/&NOW=1346612979613&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 20674 T2608 C171 P14838 REQ /select {wt=javabin&q=*:*&version=2} status=0 QTime=7 
[junit4:junit4]   2> 20675 T2596 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:14835/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@71f63252
[junit4:junit4]   2> 20676 T2684 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:14835
[junit4:junit4]   2> 20676 T2596 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 20677 T2684 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:14835, initiating session
[junit4:junit4]   2> 20677 T2598 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:14909
[junit4:junit4]   2> 20677 T2598 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:14909
[junit4:junit4]   2> 20678 T2600 oazs.NIOServerCnxn.finishSessionInit Established session 0x139886316ef0009 with negotiated timeout 10000 for client /140.211.11.196:14909
[junit4:junit4]   2> 20678 T2684 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:14835, sessionid = 0x139886316ef0009, negotiated timeout = 10000
[junit4:junit4]   2> 20679 T2685 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71f63252 name:ZooKeeperConnection Watcher:127.0.0.1:14835/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 20679 T2596 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 20680 T2596 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 20681 T2601 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139886316ef0009
[junit4:junit4]   2> 20682 T2685 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 20682 T2598 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:14909 which had sessionid 0x139886316ef0009
[junit4:junit4]   2> 20682 T2596 oaz.ZooKeeper.close Session: 0x139886316ef0009 closed
[junit4:junit4]   2> 20684 T2628 C172 P14856 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 20686 T2640 C173 P14860 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 20690 T2648 C169 P14867 REQ /select {fl=id,score&shard.url=127.0.0.1:14856/solr/collection1/|127.0.0.1:14867/solr/collection1/&NOW=1346612979633&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 20691 T2660 C170 P14870 REQ /select {fl=id,score&shard.url=127.0.0.1:14860/solr/collection1/|127.0.0.1:14870/solr/collection1/&NOW=1346612979633&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 20694 T2648 C169 P14867 REQ /select {shard.url=127.0.0.1:14856/solr/collection1/|127.0.0.1:14867/solr/collection1/&NOW=1346612979633&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 20695 T2647 C169 P14867 REQ /select {wt=javabin&q=*:*&version=2} status=0 QTime=8 
[junit4:junit4]   2> 20701 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[2 (1412026051743186944)]} 0 3
[junit4:junit4]   2> 20715 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 20716 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 20717 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[2]} 0 12
[junit4:junit4]   2> 20720 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[3 (1412026051765207040)]} 0 1
[junit4:junit4]   2> 20729 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20730 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 20730 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[3]} 0 7
[junit4:junit4]   2> 20734 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[4 (1412026051779887104)]} 0 1
[junit4:junit4]   2> 20746 T2646 C169 P14867 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 20747 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[4 (1412026051784081408)]} 0 10
[junit4:junit4]   2> 20751 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[5 (1412026051797712896)]} 0 1
[junit4:junit4]   2> 20761 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20762 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 20762 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[5]} 0 8
[junit4:junit4]   2> 20766 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[6 (1412026051813441536)]} 0 1
[junit4:junit4]   2> 20774 T2659 C170 P14870 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20775 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[6 (1412026051817635840)]} 0 6
[junit4:junit4]   2> 20779 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[7 (1412026051827073024)]} 0 1
[junit4:junit4]   2> 20788 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20789 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 20789 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[7]} 0 7
[junit4:junit4]   2> 20793 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[8 (1412026051841753088)]} 0 1
[junit4:junit4]   2> 20800 T2646 C169 P14867 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20801 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[8 (1412026051845947392)]} 0 5
[junit4:junit4]   2> 20805 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[9 (1412026051854336000)]} 0 1
[junit4:junit4]   2> 20812 T2659 C170 P14870 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20813 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[9 (1412026051858530304)]} 0 5
[junit4:junit4]   2> 20817 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[10 (1412026051866918912)]} 0 1
[junit4:junit4]   2> 20826 T2646 C169 P14867 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14856/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20827 T2623 C172 P14856 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 20827 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[10]} 0 7
[junit4:junit4]   2> 20844 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[11 (1412026051881598976)]} 0 14
[junit4:junit4]   2> 20854 T2646 C169 P14867 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14856/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20855 T2623 C172 P14856 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 20856 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[11]} 0 9
[junit4:junit4]   2> 20860 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[12 (1412026051910959104)]} 0 2
[junit4:junit4]   2> 20867 T2646 C169 P14867 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20868 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[12 (1412026051916201984)]} 0 5
[junit4:junit4]   2> 20872 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[13 (1412026051924590592)]} 0 1
[junit4:junit4]   2> 20880 T2646 C169 P14867 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20881 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[13 (1412026051928784896)]} 0 6
[junit4:junit4]   2> 20885 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[14 (1412026051938222080)]} 0 1
[junit4:junit4]   2> 20892 T2646 C169 P14867 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20893 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[14 (1412026051942416384)]} 0 5
[junit4:junit4]   2> 20896 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[15 (1412026051949756416)]} 0 1
[junit4:junit4]   2> 20903 T2646 C169 P14867 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20904 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[15 (1412026051953950720)]} 0 5
[junit4:junit4]   2> 20907 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[16 (1412026051961290752)]} 0 1
[junit4:junit4]   2> 20914 T2646 C169 P14867 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20915 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[16 (1412026051965485056)]} 0 5
[junit4:junit4]   2> 20919 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[17 (1412026051971776512)]} 0 3
[junit4:junit4]   2> 20934 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 20935 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 20935 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[17]} 0 13
[junit4:junit4]   2> 20939 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[100 (1412026051994845184)]} 0 1
[junit4:junit4]   2> 20971 T2646 C169 P14867 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=13 
[junit4:junit4]   2> 20972 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[100 (1412026051999039488)]} 0 30
[junit4:junit4]   2> 20975 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[101 (1412026052032593920)]} 0 1
[junit4:junit4]   2> 20984 T2646 C169 P14867 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 20985 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[101 (1412026052036788224)]} 0 7
[junit4:junit4]   2> 20988 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[102 (1412026052046225408)]} 0 1
[junit4:junit4]   2> 20997 T2646 C169 P14867 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14856/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20998 T2623 C172 P14856 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 20998 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[102]} 0 7
[junit4:junit4]   2> 21017 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[103 (1412026052060905472)]} 0 16
[junit4:junit4]   2> 21024 T2659 C170 P14870 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21025 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[103 (1412026052080828416)]} 0 5
[junit4:junit4]   2> 21029 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[104 (1412026052088168448)]} 0 2
[junit4:junit4]   2> 21038 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21039 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 21039 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[104]} 0 7
[junit4:junit4]   2> 21043 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[105 (1412026052103897088)]} 0 1
[junit4:junit4]   2> 21074 T2659 C170 P14870 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=13 
[junit4:junit4]   2> 21074 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[105 (1412026052108091392)]} 0 28
[junit4:junit4]   2> 21078 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[106 (1412026052140597248)]} 0 1
[junit4:junit4]   2> 21088 T2659 C170 P14870 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 21088 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[106 (1412026052144791552)]} 0 7
[junit4:junit4]   2> 21092 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[107 (1412026052155277312)]} 0 1
[junit4:junit4]   2> 21099 T2646 C169 P14867 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21100 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[107 (1412026052159471616)]} 0 5
[junit4:junit4]   2> 21103 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[108 (1412026052166811648)]} 0 1
[junit4:junit4]   2> 21111 T2646 C169 P14867 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14856/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21111 T2623 C172 P14856 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 21112 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[108]} 0 7
[junit4:junit4]   2> 21116 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[109 (1412026052180443136)]} 0 1
[junit4:junit4]   2> 21124 T2646 C169 P14867 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14856/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21124 T2623 C172 P14856 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 21125 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[109]} 0 7
[junit4:junit4]   2> 21129 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[110 (1412026052194074624)]} 0 1
[junit4:junit4]   2> 21135 T2646 C169 P14867 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21135 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[110 (1412026052197220352)]} 0 4
[junit4:junit4]   2> 21139 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[111 (1412026052204560384)]} 0 1
[junit4:junit4]   2> 21148 T2646 C169 P14867 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14856/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21148 T2623 C172 P14856 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 21149 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[111]} 0 7
[junit4:junit4]   2> 21153 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[112 (1412026052219240448)]} 0 1
[junit4:junit4]   2> 21159 T2659 C170 P14870 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21159 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[112 (1412026052222386176)]} 0 4
[junit4:junit4]   2> 21175 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[113 (1412026052229726208)]} 0 13
[junit4:junit4]   2> 21182 T2646 C169 P14867 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21182 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[113 (1412026052246503424)]} 0 4
[junit4:junit4]   2> 21187 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[114 (1412026052253843456)]} 0 2
[junit4:junit4]   2> 21196 T2646 C169 P14867 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14856/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21197 T2623 C172 P14856 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 21197 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[114]} 0 7
[junit4:junit4]   2> 21201 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[115 (1412026052269572096)]} 0 1
[junit4:junit4]   2> 21210 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21211 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 21211 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[115]} 0 7
[junit4:junit4]   2> 21215 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[116 (1412026052284252160)]} 0 1
[junit4:junit4]   2> 21223 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21223 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 21224 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[116]} 0 7
[junit4:junit4]   2> 21228 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[117 (1412026052297883648)]} 0 1
[junit4:junit4]   2> 21237 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21237 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 21238 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[117]} 0 7
[junit4:junit4]   2> 21242 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[118 (1412026052312563712)]} 0 1
[junit4:junit4]   2> 21273 T2646 C169 P14867 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14856/solr/collection1/&wt=javabin&version=2} status=0 QTime=12 
[junit4:junit4]   2> 21274 T2623 C172 P14856 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=27 
[junit4:junit4]   2> 21274 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[118]} 0 29
[junit4:junit4]   2> 21278 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[119 (1412026052350312448)]} 0 1
[junit4:junit4]   2> 21285 T2659 C170 P14870 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21285 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[119 (1412026052354506752)]} 0 4
[junit4:junit4]   2> 21289 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[120 (1412026052361846784)]} 0 1
[junit4:junit4]   2> 21298 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21298 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 21299 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[120]} 0 7
[junit4:junit4]   2> 21303 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[121 (1412026052376526848)]} 0 1
[junit4:junit4]   2> 21308 T2659 C170 P14870 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21308 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[121 (1412026052378624000)]} 0 4
[junit4:junit4]   2> 21312 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[122 (1412026052385964032)]} 0 1
[junit4:junit4]   2> 21322 T2646 C169 P14867 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14856/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 21322 T2623 C172 P14856 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 21323 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[122]} 0 9
[junit4:junit4]   2> 21339 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[123 (1412026052401692672)]} 0 13
[junit4:junit4]   2> 21347 T2646 C169 P14867 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14856/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21347 T2623 C172 P14856 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 21348 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[123]} 0 7
[junit4:junit4]   2> 21353 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[124 (1412026052427907072)]} 0 2
[junit4:junit4]   2> 21360 T2646 C169 P14867 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21361 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[124 (1412026052433149952)]} 0 5
[junit4:junit4]   2> 21364 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[125 (1412026052440489984)]} 0 1
[junit4:junit4]   2> 21372 T2646 C169 P14867 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14856/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21373 T2623 C172 P14856 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 21373 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[125]} 0 7
[junit4:junit4]   2> 21377 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[126 (1412026052454121472)]} 0 1
[junit4:junit4]   2> 21383 T2659 C170 P14870 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21383 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[126 (1412026052457267200)]} 0 4
[junit4:junit4]   2> 21387 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[127 (1412026052464607232)]} 0 1
[junit4:junit4]   2> 21415 T2659 C170 P14870 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=12 
[junit4:junit4]   2> 21416 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[127 (1412026052467752960)]} 0 27
[junit4:junit4]   2> 21419 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[128 (1412026052498161664)]} 0 1
[junit4:junit4]   2> 21429 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 21429 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 21430 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[128]} 0 9
[junit4:junit4]   2> 21434 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[129 (1412026052513890304)]} 0 1
[junit4:junit4]   2> 21443 T2646 C169 P14867 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14856/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21444 T2623 C172 P14856 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 21444 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[129]} 0 7
[junit4:junit4]   2> 21448 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[130 (1412026052528570368)]} 0 1
[junit4:junit4]   2> 21456 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21456 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 21457 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[130]} 0 7
[junit4:junit4]   2> 21461 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[131 (1412026052542201856)]} 0 1
[junit4:junit4]   2> 21469 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21469 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 21470 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[131]} 0 7
[junit4:junit4]   2> 21474 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[132 (1412026052555833344)]} 0 1
[junit4:junit4]   2> 21480 T2646 C169 P14867 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21480 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[132 (1412026052558979072)]} 0 4
[junit4:junit4]   2> 21496 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[133 (1412026052566319104)]} 0 13
[junit4:junit4]   2> 21505 T2646 C169 P14867 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14856/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21506 T2623 C172 P14856 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 21506 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[133]} 0 7
[junit4:junit4]   2> 21511 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[134 (1412026052593582080)]} 0 2
[junit4:junit4]   2> 21517 T2659 C170 P14870 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21517 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[134 (1412026052597776384)]} 0 4
[junit4:junit4]   2> 21521 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[135 (1412026052605116416)]} 0 1
[junit4:junit4]   2> 21527 T2646 C169 P14867 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21527 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[135 (1412026052608262144)]} 0 4
[junit4:junit4]   2> 21531 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[136 (1412026052615602176)]} 0 1
[junit4:junit4]   2> 21538 T2659 C170 P14870 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21538 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[136 (1412026052619796480)]} 0 4
[junit4:junit4]   2> 21542 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[137 (1412026052627136512)]} 0 1
[junit4:junit4]   2> 21550 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21550 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 21551 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[137]} 0 7
[junit4:junit4]   2> 21555 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[138 (1412026052640768000)]} 0 1
[junit4:junit4]   2> 21561 T2646 C169 P14867 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21562 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[138 (1412026052643913728)]} 0 5
[junit4:junit4]   2> 21565 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[139 (1412026052651253760)]} 0 1
[junit4:junit4]   2> 21573 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21573 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 21574 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[139]} 0 7
[junit4:junit4]   2> 21578 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[140 (1412026052664885248)]} 0 1
[junit4:junit4]   2> 21584 T2659 C170 P14870 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21584 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[140 (1412026052668030976)]} 0 4
[junit4:junit4]   2> 21588 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[141 (1412026052675371008)]} 0 1
[junit4:junit4]   2> 21597 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21597 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 21598 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[141]} 0 7
[junit4:junit4]   2> 21602 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[142 (1412026052690051072)]} 0 1
[junit4:junit4]   2> 21632 T2659 C170 P14870 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=13 
[junit4:junit4]   2> 21632 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[142 (1412026052694245376)]} 0 27
[junit4:junit4]   2> 21649 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[143 (1412026052725702656)]} 0 14
[junit4:junit4]   2> 21657 T2659 C170 P14870 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 21658 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[143 (1412026052742479872)]} 0 7
[junit4:junit4]   2> 21663 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[144 (1412026052752965632)]} 0 2
[junit4:junit4]   2> 21671 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21672 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 21672 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[144]} 0 7
[junit4:junit4]   2> 21676 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[145 (1412026052767645696)]} 0 1
[junit4:junit4]   2> 21684 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21685 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 21685 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[145]} 0 7
[junit4:junit4]   2> 21689 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[146 (1412026052781277184)]} 0 1
[junit4:junit4]   2> 21718 T2646 C169 P14867 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=13 
[junit4:junit4]   2> 21719 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[146 (1412026052784422912)]} 0 28
[junit4:junit4]   2> 21722 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[147 (1412026052815880192)]} 0 1
[junit4:junit4]   2> 21729 T2659 C170 P14870 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21730 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[147 (1412026052820074496)]} 0 5
[junit4:junit4]   2> 21733 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[148 (1412026052827414528)]} 0 1
[junit4:junit4]   2> 21744 T2646 C169 P14867 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14856/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 21745 T2623 C172 P14856 REQ /update {distrib.from=http://127.0.0.1:14860/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 21746 T2635 C173 P14860 /update {wt=javabin&version=2} {add=[148]} 0 11
[junit4:junit4]   2> 21750 T2608 C171 P14838 /update {wt=javabin&version=2} {add=[149 (1412026052845240320)]} 0 1
[junit4:junit4]   2> 21759 T2659 C170 P14870 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:14860/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 21760 T2639 C173 P14860 REQ /update {distrib.from=http://127.0.0.1:14856/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 21760 T2627 C172 P14856 /update {wt=javabin&version=2} {add=[149]} 0 7
[junit4:junit4]   2> 21761 T2596 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):360
[junit4:junit4]   2> 21762 T2596 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 21765 T2608 C171 P14838 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 22184 T2608 C171 P14838 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@5f780a9a; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Block_0.pos, _0_Block_0.tip, _0_MockSep_0.pos, _0_Block_0.tim, _0_MockFixedIntBlock_0.tib, _0_Pulsing40_0.prx, _0_Pulsing40_0.frq, _0_MockFixedIntBlock_0.skp, _0_MockFixedIntBlock_0.pyl, _0_MockSep_0.skp, _0_MockFixedIntBlock_0.tii, _0_Pulsing40_0.tip, _0_MockSep_0.doc, _0.si, _0.fnm, _0_Block_0.doc, _0_Pulsing40_0.tim, _0_MockFixedIntBlock_0.pos, _0_nrm.cfs, _0_MockFixedIntBlock_0.frq, _0_MockSep_0.tib, _0_MockFixedIntBlock_0.doc, _0_nrm.cfe, _0_MockSep_0.frq, segments_2, _0.fdx, _0_MockSep_0.tii, _0_MockSep_0.pyl, _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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@5f780a9a; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[_5_nrm.cfe, _6_MockFixedIntBlock_0.pyl, _4_MockSep_0.skp, _3.fdt, _2_MockSep_0.doc, _7.fnm, _6_MockFixedIntBlock_0.skp, _6_Block_0.pos, _6_MockSep_0.doc, _5_MockSep_0.skp, _5_Pulsing40_0.tip, _6_MockSep_0.frq, _7_MockFixedIntBlock_0.pos, _7_MockFixedIntBlock_0.skp, _7_MockSep_0.tib, _5_Pulsing40_0.tim, _1_Block_0.pos, _1_MockSep_0.pyl, _0_Pulsing40_0.tim, _7_MockSep_0.tii, _4_MockFixedIntBlock_0.pos, _1_MockSep_0.tib, _5_MockSep_0.doc, _1_MockSep_0.tii, _1.fdx, _1.fdt, _3_MockSep_0.pos, _5_nrm.cfs, _4_MockFixedIntBlock_0.frq, _1_MockFixedIntBlock_0.pos, _6.fdt, _3_Pulsing40_0.frq, _2.si, _2_Pulsing40_0.tim, _2_Block_0.tim, _3_MockFixedIntBlock_0.frq, _6_MockSep_0.pyl, _2_MockSep_0.skp, _2_Pulsing40_0.tip, _2_Block_0.tip, _6.fdx, _6_MockFixedIntBlock_0.tib, _6_MockFixedIntBlock_0.tii, _5_MockSep_0.tii, _5_Block_0.tim, _2_nrm.cfe, _5_Pulsing40_0.frq, _0_Pulsing40_0.tip, _2_nrm.cfs, _6_MockFixedIntBlock_0.doc, _4_Block_0.tip, _5_MockFixedIntBlock_0.frq, _5_MockFixedIntBlock_0.tib, _7_MockFixedIntBlock_0.doc, _2.fnm, _7_Pulsing40_0.tim, _3.fdx, _4_Pulsing40_0.tip, _2_MockSep_0.pyl, _4_Pulsing40_0.tim, _1.si, _5_MockSep_0.tib, _3_MockSep_0.skp, _5_MockFixedIntBlock_0.tii, _7_Pulsing40_0.tip, _3_MockSep_0.doc, _3_nrm.cfe, _0_Block_0.tip, _3_MockFixedIntBlock_0.skp, _4_MockFixedIntBlock_0.tib, _0_Block_0.tim, _1_MockFixedIntBlock_0.pyl, _7_Block_0.tim, _4_nrm.cfe, _7_Block_0.tip, _0_Pulsing40_0.prx, _4.fdx, _1_Pulsing40_0.prx, _2_MockFixedIntBlock_0.frq, _4_MockFixedIntBlock_0.tii, _7_MockSep_0.pos, _1_Block_0.doc, _6_MockSep_0.tii, _1_MockSep_0.doc, _6_MockSep_0.tib, _5.si, _3_nrm.cfs, _6_MockFixedIntBlock_0.pos, _5_MockFixedIntBlock_0.skp, _1_MockFixedIntBlock_0.skp, _4_MockFixedIntBlock_0.doc, _6_Pulsing40_0.prx, _4_nrm.cfs, _5_Block_0.tip, _5_MockSep_0.pyl, _7_Block_0.doc, _1_MockFixedIntBlock_0.doc, _3_MockFixedIntBlock_0.doc, _7_MockFixedIntBlock_0.tib, _6_nrm.cfs, _7_nrm.cfs, _5_Block_0.pos, _7_MockFixedIntBlock_0.tii, _0_MockSep_0.doc, _4_MockFixedIntBlock_0.pyl, _1_nrm.cfs, _1_MockFixedIntBlock_0.tii, _5.fnm, _0_Block_0.doc, _7_nrm.cfe, _5_MockFixedIntBlock_0.pos, _6_nrm.cfe, _5_MockFixedIntBlock_0.doc, _7_MockFixedIntBlock_0.pyl, _2_MockSep_0.frq, _4.fdt, _4.si, _1_nrm.cfe, _4_Pulsing40_0.frq, _6_Block_0.tip, _1_MockFixedIntBlock_0.tib, _0_MockSep_0.frq, _6_Block_0.tim, _2_Block_0.pos, _0_MockSep_0.pos, _4_MockSep_0.tib, _6_MockFixedIntBlock_0.frq, _7.si, _3_MockSep_0.frq, _0_MockFixedIntBlock_0.tib, _0_Pulsing40_0.frq, _0_MockFixedIntBlock_0.tii, _4_MockSep_0.doc, _1_Block_0.tip, _1_MockSep_0.skp, _1_Block_0.tim, _2.fdt, _3_Pulsing40_0.tip, _7.fdx, _2.fdx, _7.fdt, _3_Pulsing40_0.tim, _3_Block_0.pos, _3_Block_0.doc, _7_Pulsing40_0.frq, _7_MockSep_0.doc, _4_MockSep_0.pyl, _7_Block_0.pos, _2_MockFixedIntBlock_0.doc, _3.si, _4_MockSep_0.tii, _2_MockFixedIntBlock_0.skp, _3.fnm, _3_MockSep_0.pyl, _4_Pulsing40_0.prx, _0_MockFixedIntBlock_0.pyl, _7_MockSep_0.frq, _6_MockSep_0.pos, _5_Block_0.doc, _4_Block_0.pos, _3_Block_0.tip, _1_MockSep_0.pos, _6_MockSep_0.skp, _3_MockFixedIntBlock_0.pos, _0_MockFixedIntBlock_0.doc, _5_Pulsing40_0.prx, _6.si, _6.fnm, _5_MockSep_0.pos, _5.fdt, _1_Pulsing40_0.tip, _6_Pulsing40_0.frq, _1_Pulsing40_0.tim, _4.fnm, _7_Pulsing40_0.prx, _2_MockFixedIntBlock_0.tii, _1.fnm, _1_Pulsing40_0.frq, _3_MockFixedIntBlock_0.pyl, _2_MockFixedIntBlock_0.tib, _3_Block_0.tim, _2_MockFixedIntBlock_0.pyl, _0_MockSep_0.skp, _7_MockSep_0.skp, _3_MockSep_0.tib, _6_Pulsing40_0.tim, _6_Pulsing40_0.tip, _2_Pulsing40_0.prx, _0.fnm, _4_Block_0.tim, _1_MockFixedIntBlock_0.frq, _4_MockSep_0.pos, _5_MockFixedIntBlock_0.pyl, _4_MockFixedIntBlock_0.skp, _6_Block_0.doc, _5_MockSep_0.frq, _0_MockFixedIntBlock_0.pos, _2_MockSep_0.tii, _2_MockSep_0.tib, _3_MockSep_0.tii, _2_Pulsing40_0.frq, _2_MockFixedIntBlock_0.pos, _2_MockSep_0.pos, _1_MockSep_0.frq, _0_Block_0.pos, _7_MockFixedIntBlock_0.frq, _4_Block_0.doc, _0_MockFixedIntBlock_0.skp, _7_MockSep_0.pyl, _0.si, _3_MockFixedIntBlock_0.tib, _0_nrm.cfs, _0_MockSep_0.tib, _0_MockFixedIntBlock_0.frq, _3_Pulsing40_0.prx, _0_nrm.cfe, _4_MockSep_0.frq, _5.fdx, _0.fdx, _0_MockSep_0.tii, _2_Block_0.doc, _0_MockSep_0.pyl, segments_3, _0.fdt, _3_MockFixedIntBlock_0.tii]
[junit4:junit4]   2> 22186 T2608 C171 P14838 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 22363 T2608 C171 P14838 oass.SolrIndexSearcher.<init> Opening Searcher@38992ee0 main
[junit4:junit4]   2> 22364 T2608 C171 P14838 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 22365 T2619 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@38992ee0 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> 22366 T2608 C171 P14838 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 601
[junit4:junit4]   2> 22368 T2635 C173 P14860 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 22606 T2635 C173 P14860 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2daf79e; 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/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1346612958952/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2daf79e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_2_Block_0.pos, _0_MockSep_0.pos, _3.fdt, _0_MockFixedIntBlock_0.tib, _3_MockSep_0.frq, _0_Pulsing40_0.frq, _2_MockSep_0.doc, _0_MockFixedIntBlock_0.tii, _1_Block_0.tip, _1_Block_0.pos, _1_MockSep_0.pyl, _1_MockSep_0.skp, _0_Pulsing40_0.tim, _1_Block_0.tim, _1_MockSep_0.tib, _3_Pulsing40_0.tip, _2.fdt, _2.fdx, _3_Pulsing40_0.tim, _3_Block_0.pos, _1_MockSep_0.tii, _3_Block_0.doc, _1.fdx, _3_MockSep_0.pos, _1.fdt, _3.si, _2_MockFixedIntBlock_0.doc, _1_MockFixedIntBlock_0.pos, _2.si, _3_Pulsing40_0.frq, _2_Pulsing40_0.tim, _2_Block_0.tim, _3_MockFixedIntBlock_0.frq, _2_MockSep_0.skp, _2_Pulsing40_0.tip, _2_Block_0.tip, _2_MockFixedIntBlock_0.skp, _3.fnm, _3_MockSep_0.pyl, _2_nrm.cfe, _0_MockFixedIntBlock_0.pyl, _0_Pulsing40_0.tip, _2_nrm.cfs, _3_Block_0.tip, _1_MockSep_0.pos, _3_MockFixedIntBlock_0.pos, _2.fnm, _3.fdx, _2_MockSep_0.pyl, _0_MockFixedIntBlock_0.doc, _1.si, _3_MockSep_0.skp, _3_nrm.cfe, _3_MockSep_0.doc, _0_Block_0.tip, _3_MockFixedIntBlock_0.skp, _1_Pulsing40

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

4:junit4]   2> 	        at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 	  67) Thread[id=2651, name=qtp1791150576-2651, state=TIMED_WAITING, group=TGRP-BasicDistributedZk2Test]
[junit4:junit4]   2> 	        at sun.misc.Unsafe.park(Native Method)
[junit4:junit4]   2> 	        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
[junit4:junit4]   2> 	        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
[junit4:junit4]   2> 	        at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:337)
[junit4:junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:517)
[junit4:junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:39)
[junit4:junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:563)
[junit4:junit4]   2> 	        at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 	  68) Thread[id=2645, name=qtp1791150576-2645 Acceptor0 SocketConnector@0.0.0.0:14867, state=RUNNABLE, group=TGRP-BasicDistributedZk2Test]
[junit4:junit4]   2> 	        at java.net.PlainSocketImpl.socketAccept(Native Method)
[junit4:junit4]   2> 	        at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398)
[junit4:junit4]   2> 	        at java.net.ServerSocket.implAccept(ServerSocket.java:522)
[junit4:junit4]   2> 	        at java.net.ServerSocket.accept(ServerSocket.java:490)
[junit4:junit4]   2> 	        at org.eclipse.jetty.server.bio.SocketConnector.accept(SocketConnector.java:112)
[junit4:junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:933)
[junit4:junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:599)
[junit4:junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:534)
[junit4:junit4]   2> 	        at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 	  69) Thread[id=2646, name=qtp1791150576-2646, state=TIMED_WAITING, group=TGRP-BasicDistributedZk2Test]
[junit4:junit4]   2> 	        at sun.misc.Unsafe.park(Native Method)
[junit4:junit4]   2> 	        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
[junit4:junit4]   2> 	        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
[junit4:junit4]   2> 	        at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:337)
[junit4:junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:517)
[junit4:junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:39)
[junit4:junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:563)
[junit4:junit4]   2> 	        at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 	  70) Thread[id=2606, name=HashSessionScavenger-63, 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> 	  71) Thread[id=2631, name=searcherExecutor-1284-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=Block(blocksize=128), foo_b=MockFixedIntBlock(blockSize=1168), foo_d=PostingsFormat(name=MockSep), foo_f=MockFixedIntBlock(blockSize=1168), n_tl1=Block(blocksize=128), n_d1=Pulsing40(freqCutoff=10 minBlockSize=93 maxBlockSize=194), rnd_b=PostingsFormat(name=MockSep), intDefault=Pulsing40(freqCutoff=10 minBlockSize=93 maxBlockSize=194), n_td1=Block(blocksize=128), timestamp=Pulsing40(freqCutoff=10 minBlockSize=93 maxBlockSize=194), id=PostingsFormat(name=MockSep), range_facet_sl=MockFixedIntBlock(blockSize=1168), range_facet_si=Block(blocksize=128), oddField_s=MockFixedIntBlock(blockSize=1168), multiDefault=Block(blocksize=128), n_tf1=Pulsing40(freqCutoff=10 minBlockSize=93 maxBlockSize=194), n_dt1=Block(blocksize=128), n_ti1=PostingsFormat(name=MockSep), range_facet_l=Pulsing40(freqCutoff=10 minBlockSize=93 maxBlockSize=194), text=MockFixedIntBlock(blockSize=1168), _version_=Pulsing40(freqCutoff=10 minBlockSize=93 maxBlockSize=194), SubjectTerms_mfacet=Pulsing40(freqCutoff=10 minBlockSize=93 maxBlockSize=194), a_t=Pulsing40(freqCutoff=10 minBlockSize=93 maxBlockSize=194), n_tdt1=Pulsing40(freqCutoff=10 minBlockSize=93 maxBlockSize=194), other_tl1=Pulsing40(freqCutoff=10 minBlockSize=93 maxBlockSize=194), n_l1=Pulsing40(freqCutoff=10 minBlockSize=93 maxBlockSize=194), a_si=Block(blocksize=128)}, sim=DefaultSimilarity, locale=zh_CN, timezone=GB
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Oracle Corporation 1.7.0_06 (64-bit)/cpus=16,threads=74,free=184104912,total=466616320
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestMergePolicyConfig, FieldMutatingUpdateProcessorTest, DirectSolrSpellCheckerTest, HighlighterTest, ZkSolrClientTest, TestPropInjectDefaults, TestSolrCoreProperties, SolrCoreTest, TestSolrXMLSerializer, TestBM25SimilarityFactory, IndexReaderFactoryTest, TestDocSet, TestUpdate, ZkCLITest, TestQuerySenderListener, TestSort, TestRemoteStreaming, SolrIndexConfigTest, TestJmxIntegration, CoreContainerCoreInitFailuresTest, TestSurroundQueryParser, FileUtilsTest, DebugComponentTest, TestDistributedGrouping, TestBinaryField, LeaderElectionTest, TestPropInject, UpdateParamsTest, OpenExchangeRatesOrgProviderTest, LukeRequestHandlerTest, ClusterStateTest, TestUtils, DocumentBuilderTest, ReturnFieldsTest, BasicZkTest, OverseerTest, TimeZoneUtilsTest, TestCodecSupport, TestFastOutputStream, TestCSVLoader, PeerSyncTest, TestReload, TestMultiCoreConfBootstrap, TestHashPartitioner, RecoveryZkTest, LegacyHTMLStripCharFilterTest, MultiTermTest, TestPhraseSuggestions, TestFunctionQuery, DOMUtilTest, TestArbitraryIndexDir, QueryParsingTest, TestFoldingMultitermQuery, RAMDirectoryFactoryTest, TestStressVersions, FullSolrCloudDistribCmdsTest, TestReplicationHandler, LeaderElectionIntegrationTest, DistributedSpellCheckComponentTest, TestRealTimeGet, TestRandomFaceting, SpellCheckCollatorTest, SoftAutoCommitTest, WordBreakSolrSpellCheckerTest, StatsComponentTest, TestRecovery, IndexBasedSpellCheckerTest, DirectUpdateHandlerTest, TestFiltering, SortByFunctionTest, SignatureUpdateProcessorFactoryTest, CoreAdminHandlerTest, DirectSolrConnectionTest, CacheHeaderTest, PolyFieldTest, TestCSVResponseWriter, DistributedQueryElevationComponentTest, IndexSchemaTest, XsltUpdateRequestHandlerTest, TestPHPSerializedResponseWriter, FieldAnalysisRequestHandlerTest, TermVectorComponentTest, DocumentAnalysisRequestHandlerTest, SolrPluginUtilsTest, FastVectorHighlighterTest, RequiredFieldsTest, SuggesterFSTTest, SolrCmdDistributorTest, TestSearchPerf, TestSolrDeletionPolicy1, UpdateRequestProcessorFactoryTest, NoCacheHeaderTest, BadComponentTest, TestSolrDeletionPolicy2, TestXIncludeConfig, TestCollationField, NumericFieldsTest, TestNumberUtils, TestLMDirichletSimilarityFactory, TestPluginEnable, TestDefaultSimilarityFactory, DateMathParserTest, PluginInfoTest, PrimUtilsTest, SpellingQueryConverterTest, TestBadConfig, TestDocumentBuilder, TestCharFilters, TestCollationKeyRangeQueries, BasicDistributedZk2Test]
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZk2Test -Dtests.seed=D93307374A36B2F3 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=zh_CN -Dtests.timezone=GB -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] ERROR   0.00s J1 | BasicDistributedZk2Test (suite) <<<
[junit4:junit4]    > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([D93307374A36B2F3]:0)
[junit4:junit4] Completed on J1 in 7220.53s, 1 test, 2 errors <<< FAILURES!

[...truncated 5 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:144: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/module-build.xml:62: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/common-build.xml:1056: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/common-build.xml:741: There were test failures: 228 suites, 910 tests, 1 suite-level error, 1 error, 6 ignored (1 assumption)

Total time: 149 minutes 32 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