lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Linux (64bit/jrockit-jdk1.6.0_33-R28.2.4-4.1.0) - Build # 4576 - Still Failing!
Date Tue, 05 Mar 2013 07:05:03 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/4576/
Java: 64bit/jrockit-jdk1.6.0_33-R28.2.4-4.1.0 -XnoOpt

1 tests failed.
FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeySafeLeaderTest

Error Message:
1 thread leaked from SUITE scope at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest:     1) Thread[id=2123, name=TEST-ChaosMonkeySafeLeaderTest.testDistribSearch-seed#[E22BFD0C90735963]-EventThread, state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]         at java.lang.Thread.sleep(Native Method)         at org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:428)         at org.apache.solr.common.cloud.ZkStateReader.getLeaderUrl(ZkStateReader.java:404)         at org.apache.solr.cloud.ZkController.getLeader(ZkController.java:833)         at org.apache.solr.cloud.ZkController.register(ZkController.java:766)         at org.apache.solr.cloud.ZkController$1.command(ZkController.java:212)         at org.apache.solr.common.cloud.ConnectionManager$1.update(ConnectionManager.java:117)         at org.apache.solr.common.cloud.DefaultConnectionStrategy.reconnect(DefaultConnectionStrategy.java:46)         at org.apache.solr.common.cloud.ConnectionManager.process(ConnectionManager.java:91)         at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)         at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest: 
   1) Thread[id=2123, name=TEST-ChaosMonkeySafeLeaderTest.testDistribSearch-seed#[E22BFD0C90735963]-EventThread, state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
        at java.lang.Thread.sleep(Native Method)
        at org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:428)
        at org.apache.solr.common.cloud.ZkStateReader.getLeaderUrl(ZkStateReader.java:404)
        at org.apache.solr.cloud.ZkController.getLeader(ZkController.java:833)
        at org.apache.solr.cloud.ZkController.register(ZkController.java:766)
        at org.apache.solr.cloud.ZkController$1.command(ZkController.java:212)
        at org.apache.solr.common.cloud.ConnectionManager$1.update(ConnectionManager.java:117)
        at org.apache.solr.common.cloud.DefaultConnectionStrategy.reconnect(DefaultConnectionStrategy.java:46)
        at org.apache.solr.common.cloud.ConnectionManager.process(ConnectionManager.java:91)
        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
	at __randomizedtesting.SeedInfo.seed([E22BFD0C90735963]:0)




Build Log:
[...truncated 8512 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4:junit4]   2> 0 T1904 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /um_xr/
[junit4:junit4]   2> 20 T1904 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-ChaosMonkeySafeLeaderTest-1362466196085
[junit4:junit4]   2> 21 T1904 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 22 T1905 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 22 T1905 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 22 T1905 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4]   2> 23 T1905 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4]   2> 23 T1905 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 23 T1905 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4]   2> 122 T1904 oasc.ZkTestServer.run start zk server on port:33229
[junit4:junit4]   2> 122 T1904 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:33229 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1cf5835a
[junit4:junit4]   2> 123 T1910 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:33229. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 123 T1904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 124 T1910 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:33229, initiating session
[junit4:junit4]   2> 124 T1906 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:41302
[junit4:junit4]   2> 124 T1906 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:41302
[junit4:junit4]   2> 124 T1908 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 186 T1908 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d39504a780000 with negotiated timeout 10000 for client /127.0.0.1:41302
[junit4:junit4]   2> 186 T1910 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:33229, sessionid = 0x13d39504a780000, negotiated timeout = 10000
[junit4:junit4]   2> 186 T1911 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cf5835a name:ZooKeeperConnection Watcher:127.0.0.1:33229 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 187 T1904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 187 T1904 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 190 T1909 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d39504a780000
[junit4:junit4]   2> 191 T1911 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 191 T1904 oaz.ZooKeeper.close Session: 0x13d39504a780000 closed
[junit4:junit4]   2> 191 T1906 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:41302 which had sessionid 0x13d39504a780000
[junit4:junit4]   2> 191 T1904 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:33229/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1cf5e601
[junit4:junit4]   2> 192 T1912 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:33229. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 192 T1904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 193 T1912 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:33229, initiating session
[junit4:junit4]   2> 193 T1906 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:41303
[junit4:junit4]   2> 193 T1906 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:41303
[junit4:junit4]   2> 194 T1908 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d39504a780001 with negotiated timeout 10000 for client /127.0.0.1:41303
[junit4:junit4]   2> 194 T1912 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:33229, sessionid = 0x13d39504a780001, negotiated timeout = 10000
[junit4:junit4]   2> 194 T1913 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cf5e601 name:ZooKeeperConnection Watcher:127.0.0.1:33229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 194 T1904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 194 T1904 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 197 T1904 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 198 T1904 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 200 T1904 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 202 T1904 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 202 T1904 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 209 T1904 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 210 T1904 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 213 T1904 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 213 T1904 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 215 T1904 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 215 T1904 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 217 T1904 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 217 T1904 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 219 T1904 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 220 T1904 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 222 T1904 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 222 T1904 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 224 T1904 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 224 T1904 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 226 T1904 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 227 T1904 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 228 T1909 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d39504a780001
[junit4:junit4]   2> 229 T1913 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 229 T1904 oaz.ZooKeeper.close Session: 0x13d39504a780001 closed
[junit4:junit4]   2> 229 T1906 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:41303 which had sessionid 0x13d39504a780001
[junit4:junit4]   2> 288 T1904 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 295 T1904 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53417
[junit4:junit4]   2> 295 T1904 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 296 T1904 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 296 T1904 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1362466196293
[junit4:junit4]   2> 296 T1904 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1362466196293/solr.xml
[junit4:junit4]   2> 296 T1904 oasc.CoreContainer.<init> New CoreContainer 488124082
[junit4:junit4]   2> 297 T1904 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1362466196293/'
[junit4:junit4]   2> 297 T1904 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1362466196293/'
[junit4:junit4]   2> 313 T1904 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 314 T1904 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 314 T1904 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 314 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 314 T1904 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 315 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 315 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 315 T1904 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 316 T1904 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 316 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 323 T1904 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 337 T1904 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:33229/solr
[junit4:junit4]   2> 337 T1904 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 338 T1904 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:33229 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1d0b9b8d
[junit4:junit4]   2> 339 T1923 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:33229. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 338 T1904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 339 T1923 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:33229, initiating session
[junit4:junit4]   2> 339 T1906 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:41304
[junit4:junit4]   2> 339 T1906 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:41304
[junit4:junit4]   2> 340 T1908 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d39504a780002 with negotiated timeout 20000 for client /127.0.0.1:41304
[junit4:junit4]   2> 340 T1923 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:33229, sessionid = 0x13d39504a780002, negotiated timeout = 20000
[junit4:junit4]   2> 340 T1924 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d0b9b8d name:ZooKeeperConnection Watcher:127.0.0.1:33229 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 340 T1904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 341 T1909 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d39504a780002
[junit4:junit4]   2> 342 T1924 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 342 T1904 oaz.ZooKeeper.close Session: 0x13d39504a780002 closed
[junit4:junit4]   2> 342 T1906 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:41304 which had sessionid 0x13d39504a780002
[junit4:junit4]   2> 342 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 345 T1904 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:33229/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1d06b906
[junit4:junit4]   2> 346 T1925 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:33229. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 346 T1904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 346 T1925 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:33229, initiating session
[junit4:junit4]   2> 346 T1906 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:41305
[junit4:junit4]   2> 346 T1906 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:41305
[junit4:junit4]   2> 347 T1908 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d39504a780003 with negotiated timeout 20000 for client /127.0.0.1:41305
[junit4:junit4]   2> 347 T1925 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:33229, sessionid = 0x13d39504a780003, negotiated timeout = 20000
[junit4:junit4]   2> 347 T1926 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d06b906 name:ZooKeeperConnection Watcher:127.0.0.1:33229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 348 T1904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 349 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 350 T1904 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 351 T1904 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53417_um_xr
[junit4:junit4]   2> 351 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:53417_um_xr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:53417_um_xr
[junit4:junit4]   2> 352 T1904 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53417_um_xr
[junit4:junit4]   2> 354 T1904 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 358 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780003 type:delete cxid:0x16 zxid:0x21 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 359 T1904 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 361 T1904 oasc.Overseer.start Overseer (id=89290584626823171-127.0.0.1:53417_um_xr-n_0000000000) starting
[junit4:junit4]   2> 361 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 362 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 362 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 363 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 364 T1928 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 364 T1904 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 366 T1904 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 367 T1927 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 370 T1929 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1362466196293/collection1
[junit4:junit4]   2> 370 T1929 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 371 T1929 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 371 T1929 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 372 T1929 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1362466196293/collection1/'
[junit4:junit4]   2> 372 T1929 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1362466196293/collection1/lib/README' to classloader
[junit4:junit4]   2> 372 T1929 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1362466196293/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 414 T1929 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 457 T1929 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 458 T1929 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 463 T1929 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 927 T1929 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 934 T1929 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 937 T1929 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 946 T1929 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 949 T1929 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 952 T1929 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 953 T1929 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 953 T1929 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 953 T1929 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 954 T1929 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 954 T1929 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 955 T1929 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1362466196293/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/control/data/
[junit4:junit4]   2> 955 T1929 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1c1fa491
[junit4:junit4]   2> 955 T1929 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 961 T1929 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/control/data forceNew:false
[junit4:junit4]   2> 962 T1929 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/control/data
[junit4:junit4]   2> 962 T1929 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/control/data/index/
[junit4:junit4]   2> 962 T1929 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 962 T1929 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/control/data/index forceNew:false
[junit4:junit4]   2> 965 T1929 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/control/data/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 965 T1929 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 966 T1929 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/control/data/index
[junit4:junit4]   2> 967 T1929 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 967 T1929 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 967 T1929 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 967 T1929 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 968 T1929 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 968 T1929 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 968 T1929 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 969 T1929 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 969 T1929 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 971 T1929 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 973 T1929 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/control/data
[junit4:junit4]   2> 974 T1929 oass.SolrIndexSearcher.<init> Opening Searcher@1c5f3ebe main
[junit4:junit4]   2> 974 T1929 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 974 T1929 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 978 T1929 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/control/data
[junit4:junit4]   2> 979 T1930 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1c5f3ebe main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 979 T1929 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 979 T1929 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 981 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780003 type:create cxid:0x50 zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4]   2> 1870 T1927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 1871 T1927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53417_um_xr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53417/um_xr"}
[junit4:junit4]   2> 1871 T1927 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 1875 T1927 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 1875 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780003 type:create cxid:0x58 zxid:0x2c txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 1879 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 1984 T1929 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 1984 T1929 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53417/um_xr collection:control_collection shard:shard1
[junit4:junit4]   2> 1985 T1929 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 1989 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780003 type:delete cxid:0x72 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 1990 T1929 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 1990 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780003 type:create cxid:0x73 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1991 T1929 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 1991 T1929 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 1992 T1929 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53417/um_xr/collection1/
[junit4:junit4]   2> 1992 T1929 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 1992 T1929 oasc.SyncStrategy.syncToMe http://127.0.0.1:53417/um_xr/collection1/ has no replicas
[junit4:junit4]   2> 1992 T1929 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53417/um_xr/collection1/
[junit4:junit4]   2> 1992 T1929 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 1995 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780003 type:create cxid:0x7d zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3383 T1927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3391 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 3403 T1929 oasc.ZkController.register We are http://127.0.0.1:53417/um_xr/collection1/ and leader is http://127.0.0.1:53417/um_xr/collection1/
[junit4:junit4]   2> 3404 T1929 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53417/um_xr
[junit4:junit4]   2> 3404 T1929 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 3404 T1929 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 3405 T1929 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 3408 T1929 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3410 T1904 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 3410 T1904 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 3411 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 3416 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 3417 T1904 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:33229/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1c720fdb
[junit4:junit4]   2> 3418 T1932 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:33229. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 3418 T1904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3418 T1932 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:33229, initiating session
[junit4:junit4]   2> 3418 T1906 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:41306
[junit4:junit4]   2> 3419 T1906 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:41306
[junit4:junit4]   2> 3420 T1908 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d39504a780004 with negotiated timeout 10000 for client /127.0.0.1:41306
[junit4:junit4]   2> 3420 T1932 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:33229, sessionid = 0x13d39504a780004, negotiated timeout = 10000
[junit4:junit4]   2> 3420 T1933 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c720fdb name:ZooKeeperConnection Watcher:127.0.0.1:33229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3421 T1904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3422 T1904 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3424 T1904 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 3485 T1904 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 3487 T1904 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55383
[junit4:junit4]   2> 3487 T1904 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 3488 T1904 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3488 T1904 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1362466199488
[junit4:junit4]   2> 3488 T1904 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1362466199488/solr.xml
[junit4:junit4]   2> 3489 T1904 oasc.CoreContainer.<init> New CoreContainer 478254280
[junit4:junit4]   2> 3489 T1904 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1362466199488/'
[junit4:junit4]   2> 3489 T1904 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1362466199488/'
[junit4:junit4]   2> 3506 T1904 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 3506 T1904 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 3506 T1904 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 3507 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 3507 T1904 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 3507 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 3508 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 3508 T1904 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 3508 T1904 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 3508 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 3517 T1904 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 3530 T1904 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:33229/solr
[junit4:junit4]   2> 3530 T1904 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 3531 T1904 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:33229 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1c9a2c41
[junit4:junit4]   2> 3532 T1943 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:33229. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 3532 T1904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3532 T1943 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:33229, initiating session
[junit4:junit4]   2> 3532 T1906 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:41307
[junit4:junit4]   2> 3532 T1906 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:41307
[junit4:junit4]   2> 3533 T1908 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d39504a780005 with negotiated timeout 20000 for client /127.0.0.1:41307
[junit4:junit4]   2> 3533 T1943 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:33229, sessionid = 0x13d39504a780005, negotiated timeout = 20000
[junit4:junit4]   2> 3533 T1944 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c9a2c41 name:ZooKeeperConnection Watcher:127.0.0.1:33229 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3534 T1904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3534 T1909 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d39504a780005
[junit4:junit4]   2> 3535 T1944 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 3535 T1904 oaz.ZooKeeper.close Session: 0x13d39504a780005 closed
[junit4:junit4]   2> 3535 T1906 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:41307 which had sessionid 0x13d39504a780005
[junit4:junit4]   2> 3535 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 3539 T1904 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:33229/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1c9b2b08
[junit4:junit4]   2> 3540 T1945 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:33229. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 3540 T1904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3540 T1945 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:33229, initiating session
[junit4:junit4]   2> 3540 T1906 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:41308
[junit4:junit4]   2> 3540 T1906 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:41308
[junit4:junit4]   2> 3541 T1908 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d39504a780006 with negotiated timeout 20000 for client /127.0.0.1:41308
[junit4:junit4]   2> 3541 T1945 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:33229, sessionid = 0x13d39504a780006, negotiated timeout = 20000
[junit4:junit4]   2> 3541 T1946 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c9b2b08 name:ZooKeeperConnection Watcher:127.0.0.1:33229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3542 T1904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3542 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780006 type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3543 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780006 type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3544 T1904 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4546 T1904 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55383_um_xr
[junit4:junit4]   2> 4547 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780006 type:delete cxid:0x9 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:55383_um_xr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:55383_um_xr
[junit4:junit4]   2> 4548 T1904 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55383_um_xr
[junit4:junit4]   2> 4549 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 4550 T1933 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 4550 T1946 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 4550 T1926 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 4554 T1947 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1362466199488/collection1
[junit4:junit4]   2> 4555 T1947 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 4555 T1947 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 4555 T1947 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 4556 T1947 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1362466199488/collection1/'
[junit4:junit4]   2> 4557 T1947 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1362466199488/collection1/lib/README' to classloader
[junit4:junit4]   2> 4557 T1947 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1362466199488/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 4587 T1947 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 4632 T1947 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 4633 T1947 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 4639 T1947 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 4896 T1927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4897 T1927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:53417_um_xr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:53417/um_xr"}
[junit4:junit4]   2> 4899 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 4899 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 4900 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 5100 T1947 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 5106 T1947 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 5110 T1947 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 5122 T1947 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5125 T1947 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5128 T1947 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5130 T1947 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 5130 T1947 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 5130 T1947 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5131 T1947 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 5131 T1947 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 5131 T1947 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1362466199488/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty1/
[junit4:junit4]   2> 5131 T1947 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1c1fa491
[junit4:junit4]   2> 5132 T1947 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 5132 T1947 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty1 forceNew:false
[junit4:junit4]   2> 5132 T1947 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty1
[junit4:junit4]   2> 5133 T1947 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty1/index/
[junit4:junit4]   2> 5133 T1947 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 5133 T1947 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty1/index forceNew:false
[junit4:junit4]   2> 5136 T1947 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty1/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 5137 T1947 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 5137 T1947 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty1/index
[junit4:junit4]   2> 5138 T1947 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 5138 T1947 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 5138 T1947 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 5139 T1947 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 5139 T1947 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 5140 T1947 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 5140 T1947 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 5140 T1947 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 5140 T1947 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 5142 T1947 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 5145 T1947 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty1
[junit4:junit4]   2> 5146 T1947 oass.SolrIndexSearcher.<init> Opening Searcher@1c76f0c4 main
[junit4:junit4]   2> 5146 T1947 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 5146 T1947 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 5152 T1948 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1c76f0c4 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 5154 T1947 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 5155 T1947 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 6403 T1927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6404 T1927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:55383_um_xr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:55383/um_xr"}
[junit4:junit4]   2> 6404 T1927 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 3
[junit4:junit4]   2> 6404 T1927 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 6408 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 6408 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 6408 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 7156 T1947 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 7157 T1947 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55383/um_xr collection:collection1 shard:shard1
[junit4:junit4]   2> 7157 T1947 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 7163 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780006 type:delete cxid:0x46 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 7163 T1947 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 7164 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780006 type:create cxid:0x47 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7165 T1947 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 7165 T1947 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 7165 T1947 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55383/um_xr/collection1/
[junit4:junit4]   2> 7166 T1947 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 7166 T1947 oasc.SyncStrategy.syncToMe http://127.0.0.1:55383/um_xr/collection1/ has no replicas
[junit4:junit4]   2> 7166 T1947 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55383/um_xr/collection1/
[junit4:junit4]   2> 7166 T1947 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 7170 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780006 type:create cxid:0x51 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7912 T1927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8026 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 8026 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 8026 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 8073 T1947 oasc.ZkController.register We are http://127.0.0.1:55383/um_xr/collection1/ and leader is http://127.0.0.1:55383/um_xr/collection1/
[junit4:junit4]   2> 8074 T1947 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55383/um_xr
[junit4:junit4]   2> 8074 T1947 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 8074 T1947 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 8074 T1947 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 8076 T1947 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8077 T1904 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 8077 T1904 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 8078 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 8141 T1904 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 8143 T1904 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:35943
[junit4:junit4]   2> 8144 T1904 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 8144 T1904 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8144 T1904 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1362466204145
[junit4:junit4]   2> 8145 T1904 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1362466204145/solr.xml
[junit4:junit4]   2> 8145 T1904 oasc.CoreContainer.<init> New CoreContainer 479639511
[junit4:junit4]   2> 8145 T1904 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1362466204145/'
[junit4:junit4]   2> 8146 T1904 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1362466204145/'
[junit4:junit4]   2> 8162 T1904 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 8163 T1904 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 8163 T1904 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 8163 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 8164 T1904 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 8164 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 8164 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 8164 T1904 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 8165 T1904 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 8165 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 8172 T1904 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 8185 T1904 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:33229/solr
[junit4:junit4]   2> 8186 T1904 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 8186 T1904 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:33229 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1c9b33bf
[junit4:junit4]   2> 8187 T1904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8187 T1959 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:33229. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 8187 T1959 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:33229, initiating session
[junit4:junit4]   2> 8188 T1906 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:41309
[junit4:junit4]   2> 8188 T1906 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:41309
[junit4:junit4]   2> 8188 T1908 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d39504a780007 with negotiated timeout 20000 for client /127.0.0.1:41309
[junit4:junit4]   2> 8188 T1959 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:33229, sessionid = 0x13d39504a780007, negotiated timeout = 20000
[junit4:junit4]   2> 8189 T1960 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c9b33bf name:ZooKeeperConnection Watcher:127.0.0.1:33229 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8189 T1904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8190 T1909 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d39504a780007
[junit4:junit4]   2> 8191 T1906 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:41309 which had sessionid 0x13d39504a780007
[junit4:junit4]   2> 8191 T1960 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 8191 T1904 oaz.ZooKeeper.close Session: 0x13d39504a780007 closed
[junit4:junit4]   2> 8191 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 8194 T1904 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:33229/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1c9c31c3
[junit4:junit4]   2> 8195 T1961 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:33229. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 8195 T1904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8195 T1961 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:33229, initiating session
[junit4:junit4]   2> 8195 T1906 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:41310
[junit4:junit4]   2> 8195 T1906 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:41310
[junit4:junit4]   2> 8196 T1908 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d39504a780008 with negotiated timeout 20000 for client /127.0.0.1:41310
[junit4:junit4]   2> 8196 T1961 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:33229, sessionid = 0x13d39504a780008, negotiated timeout = 20000
[junit4:junit4]   2> 8197 T1962 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c9c31c3 name:ZooKeeperConnection Watcher:127.0.0.1:33229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8197 T1904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8197 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780008 type:create cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8198 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780008 type:create cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8199 T1904 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9202 T1904 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35943_um_xr
[junit4:junit4]   2> 9203 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780008 type:delete cxid:0x9 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:35943_um_xr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:35943_um_xr
[junit4:junit4]   2> 9204 T1904 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35943_um_xr
[junit4:junit4]   2> 9208 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 9208 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 9209 T1933 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9209 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9209 T1962 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9211 T1926 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9211 T1946 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9219 T1963 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1362466204145/collection1
[junit4:junit4]   2> 9220 T1963 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 9221 T1963 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 9221 T1963 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 9223 T1963 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1362466204145/collection1/'
[junit4:junit4]   2> 9224 T1963 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1362466204145/collection1/lib/README' to classloader
[junit4:junit4]   2> 9225 T1963 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1362466204145/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 9254 T1963 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 9293 T1963 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 9294 T1963 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 9299 T1963 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 9532 T1927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9533 T1927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:55383_um_xr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:55383/um_xr"}
[junit4:junit4]   2> 9535 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9535 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9535 T1962 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9535 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9750 T1963 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 9757 T1963 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 9760 T1963 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 9772 T1963 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 9775 T1963 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 9778 T1963 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 9779 T1963 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 9779 T1963 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 9779 T1963 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 9780 T1963 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 9781 T1963 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 9781 T1963 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1362466204145/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty2/
[junit4:junit4]   2> 9781 T1963 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1c1fa491
[junit4:junit4]   2> 9781 T1963 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 9782 T1963 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty2 forceNew:false
[junit4:junit4]   2> 9782 T1963 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty2
[junit4:junit4]   2> 9782 T1963 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty2/index/
[junit4:junit4]   2> 9783 T1963 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 9783 T1963 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty2/index forceNew:false
[junit4:junit4]   2> 9786 T1963 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty2/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9786 T1963 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 9786 T1963 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty2/index
[junit4:junit4]   2> 9787 T1963 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 9788 T1963 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 9788 T1963 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 9788 T1963 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 9789 T1963 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 9789 T1963 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 9789 T1963 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 9790 T1963 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 9790 T1963 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 9792 T1963 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 9795 T1963 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty2
[junit4:junit4]   2> 9795 T1963 oass.SolrIndexSearcher.<init> Opening Searcher@1c8276a2 main
[junit4:junit4]   2> 9796 T1963 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 9796 T1963 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 9803 T1964 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1c8276a2 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 9806 T1963 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 9807 T1963 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 11041 T1927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11042 T1927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:35943_um_xr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:35943/um_xr"}
[junit4:junit4]   2> 11043 T1927 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4]   2> 11043 T1927 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4]   2> 11049 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 11049 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 11049 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 11049 T1962 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 11810 T1963 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 11810 T1963 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:35943/um_xr collection:collection1 shard:shard2
[junit4:junit4]   2> 11811 T1963 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 11822 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780008 type:delete cxid:0x45 zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard2 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard2
[junit4:junit4]   2> 11823 T1963 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 11824 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780008 type:create cxid:0x46 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 11827 T1963 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 11827 T1963 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 11827 T1963 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:35943/um_xr/collection1/
[junit4:junit4]   2> 11828 T1963 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 11828 T1963 oasc.SyncStrategy.syncToMe http://127.0.0.1:35943/um_xr/collection1/ has no replicas
[junit4:junit4]   2> 11829 T1963 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:35943/um_xr/collection1/
[junit4:junit4]   2> 11829 T1963 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 11835 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780008 type:create cxid:0x4f zxid:0x82 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12556 T1927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12568 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 12568 T1962 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 12568 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 12568 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 12590 T1963 oasc.ZkController.register We are http://127.0.0.1:35943/um_xr/collection1/ and leader is http://127.0.0.1:35943/um_xr/collection1/
[junit4:junit4]   2> 12591 T1963 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35943/um_xr
[junit4:junit4]   2> 12591 T1963 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 12591 T1963 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 12592 T1963 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 12594 T1963 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12596 T1904 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 12596 T1904 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 12597 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 12660 T1904 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 12663 T1904 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:35931
[junit4:junit4]   2> 12663 T1904 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 12663 T1904 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 12664 T1904 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1362466208668
[junit4:junit4]   2> 12664 T1904 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1362466208668/solr.xml
[junit4:junit4]   2> 12664 T1904 oasc.CoreContainer.<init> New CoreContainer 480735345
[junit4:junit4]   2> 12665 T1904 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1362466208668/'
[junit4:junit4]   2> 12665 T1904 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1362466208668/'
[junit4:junit4]   2> 12680 T1904 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 12681 T1904 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 12681 T1904 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 12681 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 12681 T1904 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 12682 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 12682 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 12682 T1904 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 12682 T1904 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 12683 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 12689 T1904 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 12702 T1904 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:33229/solr
[junit4:junit4]   2> 12702 T1904 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 12703 T1904 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:33229 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1c8a3360
[junit4:junit4]   2> 12704 T1975 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:33229. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 12704 T1904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12704 T1975 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:33229, initiating session
[junit4:junit4]   2> 12704 T1906 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:41336
[junit4:junit4]   2> 12704 T1906 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:41336
[junit4:junit4]   2> 12705 T1908 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d39504a780009 with negotiated timeout 20000 for client /127.0.0.1:41336
[junit4:junit4]   2> 12705 T1975 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:33229, sessionid = 0x13d39504a780009, negotiated timeout = 20000
[junit4:junit4]   2> 12705 T1976 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c8a3360 name:ZooKeeperConnection Watcher:127.0.0.1:33229 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12706 T1904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12707 T1909 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d39504a780009
[junit4:junit4]   2> 12708 T1976 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 12708 T1904 oaz.ZooKeeper.close Session: 0x13d39504a780009 closed
[junit4:junit4]   2> 12708 T1906 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:41336 which had sessionid 0x13d39504a780009
[junit4:junit4]   2> 12708 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 12711 T1904 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:33229/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1c8bcdfe
[junit4:junit4]   2> 12712 T1977 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:33229. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 12712 T1904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12712 T1977 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:33229, initiating session
[junit4:junit4]   2> 12712 T1906 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:41337
[junit4:junit4]   2> 12713 T1906 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:41337
[junit4:junit4]   2> 12713 T1908 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d39504a78000a with negotiated timeout 20000 for client /127.0.0.1:41337
[junit4:junit4]   2> 12713 T1977 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:33229, sessionid = 0x13d39504a78000a, negotiated timeout = 20000
[junit4:junit4]   2> 12714 T1978 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c8bcdfe name:ZooKeeperConnection Watcher:127.0.0.1:33229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12714 T1904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12714 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a78000a type:create cxid:0x1 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12716 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a78000a type:create cxid:0x2 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12718 T1904 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 13721 T1904 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35931_um_xr
[junit4:junit4]   2> 13722 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a78000a type:delete cxid:0x9 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:35931_um_xr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:35931_um_xr
[junit4:junit4]   2> 13723 T1904 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35931_um_xr
[junit4:junit4]   2> 13726 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 13726 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 13727 T1962 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13727 T1978 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13727 T1933 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13728 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 13728 T1962 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 13730 T1946 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13730 T1926 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13737 T1979 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1362466208668/collection1
[junit4:junit4]   2> 13738 T1979 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 13739 T1979 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 13739 T1979 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 13741 T1979 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1362466208668/collection1/'
[junit4:junit4]   2> 13742 T1979 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1362466208668/collection1/lib/README' to classloader
[junit4:junit4]   2> 13743 T1979 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1362466208668/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 13784 T1979 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 13842 T1979 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 13844 T1979 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 13851 T1979 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 14075 T1927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14075 T1927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:35943_um_xr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:35943/um_xr"}
[junit4:junit4]   2> 14079 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 14079 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 14079 T1962 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 14079 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 14080 T1978 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 14325 T1979 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 14332 T1979 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 14335 T1979 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 14348 T1979 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14352 T1979 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14359 T1979 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14361 T1979 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 14361 T1979 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 14361 T1979 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14363 T1979 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 14363 T1979 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 14364 T1979 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1362466208668/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty3/
[junit4:junit4]   2> 14364 T1979 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1c1fa491
[junit4:junit4]   2> 14365 T1979 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 14366 T1979 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty3 forceNew:false
[junit4:junit4]   2> 14366 T1979 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty3
[junit4:junit4]   2> 14367 T1979 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty3/index/
[junit4:junit4]   2> 14368 T1979 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 14368 T1979 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty3/index forceNew:false
[junit4:junit4]   2> 14373 T1979 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty3/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 14373 T1979 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 14374 T1979 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty3/index
[junit4:junit4]   2> 14376 T1979 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 14377 T1979 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 14377 T1979 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 14378 T1979 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 14379 T1979 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 14380 T1979 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 14380 T1979 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 14381 T1979 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 14382 T1979 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 14386 T1979 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 14391 T1979 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty3
[junit4:junit4]   2> 14393 T1979 oass.SolrIndexSearcher.<init> Opening Searcher@1cadbe30 main
[junit4:junit4]   2> 14393 T1979 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 14394 T1979 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 14402 T1980 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1cadbe30 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 14406 T1979 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 14406 T1979 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 15585 T1927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15587 T1927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:35931_um_xr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:35931/um_xr"}
[junit4:junit4]   2> 15587 T1927 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4]   2> 15588 T1927 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4:junit4]   2> 15593 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 15594 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 15594 T1962 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 15594 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 15594 T1978 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 16409 T1979 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 16409 T1979 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:35931/um_xr collection:collection1 shard:shard3
[junit4:junit4]   2> 16411 T1979 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4:junit4]   2> 16420 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a78000a type:delete cxid:0x45 zxid:0xa0 txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard3 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard3
[junit4:junit4]   2> 16421 T1979 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 16421 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a78000a type:create cxid:0x46 zxid:0xa1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 16424 T1979 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 16425 T1979 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 16425 T1979 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:35931/um_xr/collection1/
[junit4:junit4]   2> 16426 T1979 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 16426 T1979 oasc.SyncStrategy.syncToMe http://127.0.0.1:35931/um_xr/collection1/ has no replicas
[junit4:junit4]   2> 16426 T1979 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:35931/um_xr/collection1/
[junit4:junit4]   2> 16427 T1979 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4:junit4]   2> 16431 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a78000a type:create cxid:0x4f zxid:0xa4 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 17101 T1927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 17111 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17111 T1962 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17112 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17112 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17113 T1978 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17135 T1979 oasc.ZkController.register We are http://127.0.0.1:35931/um_xr/collection1/ and leader is http://127.0.0.1:35931/um_xr/collection1/
[junit4:junit4]   2> 17135 T1979 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35931/um_xr
[junit4:junit4]   2> 17136 T1979 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 17136 T1979 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 17136 T1979 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 17139 T1979 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 17141 T1904 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 17141 T1904 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 17142 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 17207 T1904 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 17210 T1904 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36270
[junit4:junit4]   2> 17210 T1904 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 17210 T1904 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 17211 T1904 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1362466213213
[junit4:junit4]   2> 17211 T1904 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1362466213213/solr.xml
[junit4:junit4]   2> 17211 T1904 oasc.CoreContainer.<init> New CoreContainer 477317376
[junit4:junit4]   2> 17212 T1904 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1362466213213/'
[junit4:junit4]   2> 17212 T1904 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1362466213213/'
[junit4:junit4]   2> 17228 T1904 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 17228 T1904 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 17228 T1904 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 17229 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 17229 T1904 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 17229 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 17229 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 17230 T1904 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 17230 T1904 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 17230 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 17237 T1904 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 17250 T1904 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:33229/solr
[junit4:junit4]   2> 17251 T1904 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 17251 T1904 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:33229 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1cc12f31
[junit4:junit4]   2> 17252 T1991 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:33229. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 17252 T1904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 17253 T1991 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:33229, initiating session
[junit4:junit4]   2> 17253 T1906 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:41363
[junit4:junit4]   2> 17253 T1906 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:41363
[junit4:junit4]   2> 17254 T1908 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d39504a78000b with negotiated timeout 20000 for client /127.0.0.1:41363
[junit4:junit4]   2> 17254 T1991 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:33229, sessionid = 0x13d39504a78000b, negotiated timeout = 20000
[junit4:junit4]   2> 17254 T1992 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cc12f31 name:ZooKeeperConnection Watcher:127.0.0.1:33229 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 17255 T1904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 17256 T1909 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d39504a78000b
[junit4:junit4]   2> 17256 T1906 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:41363 which had sessionid 0x13d39504a78000b
[junit4:junit4]   2> 17257 T1992 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 17256 T1904 oaz.ZooKeeper.close Session: 0x13d39504a78000b closed
[junit4:junit4]   2> 17257 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 17260 T1904 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:33229/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1cc24984
[junit4:junit4]   2> 17261 T1993 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:33229. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 17261 T1904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 17261 T1906 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:41364
[junit4:junit4]   2> 17261 T1993 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:33229, initiating session
[junit4:junit4]   2> 17262 T1906 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:41364
[junit4:junit4]   2> 17263 T1908 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d39504a78000c with negotiated timeout 20000 for client /127.0.0.1:41364
[junit4:junit4]   2> 17263 T1993 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:33229, sessionid = 0x13d39504a78000c, negotiated timeout = 20000
[junit4:junit4]   2> 17264 T1994 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cc24984 name:ZooKeeperConnection Watcher:127.0.0.1:33229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 17264 T1904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 17265 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a78000c type:create cxid:0x1 zxid:0xb1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 17266 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a78000c type:create cxid:0x2 zxid:0xb2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 17268 T1904 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 18272 T1904 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36270_um_xr
[junit4:junit4]   2> 18273 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a78000c type:delete cxid:0x9 zxid:0xb3 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:36270_um_xr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:36270_um_xr
[junit4:junit4]   2> 18275 T1904 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36270_um_xr
[junit4:junit4]   2> 18279 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 18279 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 18280 T1962 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 18280 T1933 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 18281 T1962 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18281 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18280 T1978 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 18282 T1978 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18283 T1994 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 18283 T1926 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 18284 T1946 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 18293 T1995 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1362466213213/collection1
[junit4:junit4]   2> 18293 T1995 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 18294 T1995 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 18295 T1995 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 18297 T1995 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1362466213213/collection1/'
[junit4:junit4]   2> 18298 T1995 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1362466213213/collection1/lib/README' to classloader
[junit4:junit4]   2> 18299 T1995 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1362466213213/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 18342 T1995 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 18382 T1995 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 18384 T1995 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 18403 T1995 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 18619 T1927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18620 T1927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":"shard3",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:35931_um_xr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:35931/um_xr"}
[junit4:junit4]   2> 18624 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18624 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18624 T1994 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18624 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18624 T1978 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18624 T1962 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18848 T1995 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 18854 T1995 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 18858 T1995 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 18873 T1995 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 18876 T1995 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 18881 T1995 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 18883 T1995 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 18883 T1995 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 18883 T1995 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 18885 T1995 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 18885 T1995 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 18885 T1995 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1362466213213/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4/
[junit4:junit4]   2> 18886 T1995 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1c1fa491
[junit4:junit4]   2> 18886 T1995 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 18887 T1995 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4 forceNew:false
[junit4:junit4]   2> 18887 T1995 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4
[junit4:junit4]   2> 18887 T1995 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4/index/
[junit4:junit4]   2> 18887 T1995 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 18888 T1995 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4/index forceNew:false
[junit4:junit4]   2> 18893 T1995 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 18893 T1995 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 18894 T1995 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4/index
[junit4:junit4]   2> 18896 T1995 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 18897 T1995 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 18897 T1995 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 18898 T1995 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 18899 T1995 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 18900 T1995 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 18900 T1995 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 18901 T1995 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 18902 T1995 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 18906 T1995 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 18911 T1995 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4
[junit4:junit4]   2> 18913 T1995 oass.SolrIndexSearcher.<init> Opening Searcher@1cd0fcc2 main
[junit4:junit4]   2> 18913 T1995 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 18914 T1995 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 18923 T1996 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1cd0fcc2 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 18926 T1995 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 18927 T1995 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 20130 T1927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20132 T1927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:36270_um_xr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:36270/um_xr"}
[junit4:junit4]   2> 20132 T1927 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4]   2> 20132 T1927 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 20138 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20138 T1978 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20138 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20138 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20138 T1994 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20138 T1962 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20929 T1995 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 20929 T1995 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36270/um_xr collection:collection1 shard:shard1
[junit4:junit4]   2> 20935 T1995 oasc.ZkController.register We are http://127.0.0.1:36270/um_xr/collection1/ and leader is http://127.0.0.1:55383/um_xr/collection1/
[junit4:junit4]   2> 20935 T1995 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36270/um_xr
[junit4:junit4]   2> 20936 T1995 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 20936 T1995 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C438 name=collection1 org.apache.solr.core.SolrCore@1cd00aef url=http://127.0.0.1:36270/um_xr/collection1 node=127.0.0.1:36270_um_xr C438_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:36270_um_xr, base_url=http://127.0.0.1:36270/um_xr}
[junit4:junit4]   2> 20937 T1997 C438 P36270 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 20937 T1997 C438 P36270 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 20937 T1997 C438 P36270 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 20938 T1995 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20938 T1997 C438 P36270 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 20940 T1997 C438 P36270 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 20940 T1904 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 20940 T1904 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 20941 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 21003 T1904 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 21005 T1904 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44106
[junit4:junit4]   2> 21006 T1904 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 21006 T1904 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 21006 T1904 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1362466217011
[junit4:junit4]   2> 21007 T1904 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1362466217011/solr.xml
[junit4:junit4]   2> 21007 T1904 oasc.CoreContainer.<init> New CoreContainer 483556922
[junit4:junit4]   2> 21007 T1904 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1362466217011/'
[junit4:junit4]   2> 21008 T1904 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1362466217011/'
[junit4:junit4]   2> 21023 T1904 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 21024 T1904 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 21024 T1904 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 21024 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 21024 T1904 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 21025 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 21025 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 21025 T1904 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 21025 T1904 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 21026 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 21032 T1904 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 21045 T1904 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:33229/solr
[junit4:junit4]   2> 21046 T1904 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 21046 T1904 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:33229 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1cc28ab2
[junit4:junit4]   2> 21047 T1904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 21047 T2008 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:33229. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 21047 T2008 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:33229, initiating session
[junit4:junit4]   2> 21048 T1906 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:41366
[junit4:junit4]   2> 21048 T1906 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:41366
[junit4:junit4]   2> 21049 T1908 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d39504a78000d with negotiated timeout 20000 for client /127.0.0.1:41366
[junit4:junit4]   2> 21049 T2008 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:33229, sessionid = 0x13d39504a78000d, negotiated timeout = 20000
[junit4:junit4]   2> 21049 T2009 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cc28ab2 name:ZooKeeperConnection Watcher:127.0.0.1:33229 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 21049 T1904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 21050 T1909 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d39504a78000d
[junit4:junit4]   2> 21050 T2009 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 21050 T1904 oaz.ZooKeeper.close Session: 0x13d39504a78000d closed
[junit4:junit4]   2> 21051 T1906 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:41366 which had sessionid 0x13d39504a78000d
[junit4:junit4]   2> 21051 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 21054 T1904 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:33229/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1ce00525
[junit4:junit4]   2> 21055 T2010 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:33229. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 21054 T1904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 21055 T1906 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:41367
[junit4:junit4]   2> 21055 T2010 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:33229, initiating session
[junit4:junit4]   2> 21056 T1906 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:41367
[junit4:junit4]   2> 21056 T1908 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d39504a78000e with negotiated timeout 20000 for client /127.0.0.1:41367
[junit4:junit4]   2> 21056 T2010 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:33229, sessionid = 0x13d39504a78000e, negotiated timeout = 20000
[junit4:junit4]   2> 21057 T2011 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ce00525 name:ZooKeeperConnection Watcher:127.0.0.1:33229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 21057 T1904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 21058 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a78000e type:create cxid:0x1 zxid:0xc4 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 21059 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a78000e type:create cxid:0x2 zxid:0xc5 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 21061 T1904 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 21645 T1927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 21646 T1927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:36270_um_xr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:36270/um_xr"}
[junit4:junit4]   2> 21666 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 21666 T1994 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 21666 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 21666 T1962 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 21666 T2011 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 21666 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 21666 T1978 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 22063 T1904 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44106_um_xr
[junit4:junit4]   2> 22064 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a78000e type:delete cxid:0xb zxid:0xca txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:44106_um_xr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:44106_um_xr
[junit4:junit4]   2> 22065 T1904 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44106_um_xr
[junit4:junit4]   2> 22067 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 22067 T2011 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 22067 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 22068 T1933 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 22068 T1962 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 22068 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 22068 T1978 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 22068 T1962 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 22069 T1978 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 22068 T1994 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 22069 T1994 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 22069 T1946 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 22069 T2011 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 22070 T1926 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 22074 T2012 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1362466217011/collection1
[junit4:junit4]   2> 22074 T2012 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 22075 T2012 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 22075 T2012 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 22076 T2012 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1362466217011/collection1/'
[junit4:junit4]   2> 22077 T2012 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1362466217011/collection1/lib/README' to classloader
[junit4:junit4]   2> 22077 T2012 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1362466217011/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 22106 T2012 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 22148 T2012 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 22149 T2012 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 22154 T2012 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 22599 T2012 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 22607 T2012 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 22610 T2012 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 22621 T2012 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 22624 T2012 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 22627 T2012 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 22628 T2012 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 22628 T2012 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 22628 T2012 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 22629 T2012 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 22629 T2012 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 22629 T2012 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1362466217011/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty5/
[junit4:junit4]   2> 22630 T2012 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1c1fa491
[junit4:junit4]   2> 22630 T2012 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 22630 T2012 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty5 forceNew:false
[junit4:junit4]   2> 22631 T2012 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty5
[junit4:junit4]   2> 22631 T2012 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty5/index/
[junit4:junit4]   2> 22631 T2012 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty5/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 22632 T2012 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty5/index forceNew:false
[junit4:junit4]   2> 22648 T2012 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty5/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 22648 T2012 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 22649 T2012 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty5/index
[junit4:junit4]   2> 22651 T2012 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 22651 T2012 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 22652 T2012 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 22652 T2012 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 22653 T2012 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 22653 T2012 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 22653 T2012 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 22654 T2012 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 22654 T2012 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 22656 T2012 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 22659 T2012 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty5
[junit4:junit4]   2> 22659 T2012 oass.SolrIndexSearcher.<init> Opening Searcher@1ce6c0ac main
[junit4:junit4]   2> 22660 T2012 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 22660 T2012 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 22664 T2013 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1ce6c0ac main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 22666 T2012 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 22666 T2012 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 23174 T1927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 23175 T1927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:44106_um_xr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:44106/um_xr"}
[junit4:junit4]   2> 23175 T1927 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4]   2> 23175 T1927 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4]   2> 23266 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 23273 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 23273 T1994 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 23266 T2011 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 23273 T1978 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 23273 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 23266 T1962 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 23668 T2012 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 23668 T2012 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:44106/um_xr collection:collection1 shard:shard2
[junit4:junit4]   2> 23671 T2012 oasc.ZkController.register We are http://127.0.0.1:44106/um_xr/collection1/ and leader is http://127.0.0.1:35943/um_xr/collection1/
[junit4:junit4]   2> 23671 T2012 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44106/um_xr
[junit4:junit4]   2> 23671 T2012 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 23671 T2012 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C439 name=collection1 org.apache.solr.core.SolrCore@1cc5aafa url=http://127.0.0.1:44106/um_xr/collection1 node=127.0.0.1:44106_um_xr C439_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:44106_um_xr, base_url=http://127.0.0.1:44106/um_xr}
[junit4:junit4]   2> 23672 T2014 C439 P44106 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 23672 T2014 C439 P44106 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 23672 T2012 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 23672 T2014 C439 P44106 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 23672 T2014 C439 P44106 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 23673 T1904 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 23673 T2014 C439 P44106 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 23673 T1904 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 23674 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 23734 T1904 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 23736 T1904 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40861
[junit4:junit4]   2> 23736 T1904 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 23736 T1904 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 23737 T1904 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1362466219740
[junit4:junit4]   2> 23737 T1904 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1362466219740/solr.xml
[junit4:junit4]   2> 23737 T1904 oasc.CoreContainer.<init> New CoreContainer 476964129
[junit4:junit4]   2> 23738 T1904 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1362466219740/'
[junit4:junit4]   2> 23738 T1904 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1362466219740/'
[junit4:junit4]   2> 23755 T1904 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 23755 T1904 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 23755 T1904 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 23756 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 23756 T1904 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 23756 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 23756 T1904 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 23757 T1904 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 23757 T1904 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 23757 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 23764 T1904 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 23778 T1904 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:33229/solr
[junit4:junit4]   2> 23778 T1904 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 23778 T1904 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:33229 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1c84a568
[junit4:junit4]   2> 23779 T2025 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:33229. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 23779 T1904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 23780 T2025 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:33229, initiating session
[junit4:junit4]   2> 23780 T1906 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:41369
[junit4:junit4]   2> 23780 T1906 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:41369
[junit4:junit4]   2> 23781 T1908 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d39504a78000f with negotiated timeout 20000 for client /127.0.0.1:41369
[junit4:junit4]   2> 23781 T2025 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:33229, sessionid = 0x13d39504a78000f, negotiated timeout = 20000
[junit4:junit4]   2> 23781 T2026 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c84a568 name:ZooKeeperConnection Watcher:127.0.0.1:33229 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 23782 T1904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 23782 T1909 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d39504a78000f
[junit4:junit4]   2> 23783 T1906 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:41369 which had sessionid 0x13d39504a78000f
[junit4:junit4]   2> 23783 T2026 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 23783 T1904 oaz.ZooKeeper.close Session: 0x13d39504a78000f closed
[junit4:junit4]   2> 23784 T1904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 23786 T1904 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:33229/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1c84411b
[junit4:junit4]   2> 23787 T2027 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:33229. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4]   2> 23787 T1904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 23788 T2027 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:33229, initiating session
[junit4:junit4]   2> 23788 T1906 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:41370
[junit4:junit4]   2> 23788 T1906 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:41370
[junit4:junit4]   2> 23789 T1908 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d39504a780010 with negotiated timeout 20000 for client /127.0.0.1:41370
[junit4:junit4]   2> 23789 T2027 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:33229, sessionid = 0x13d39504a780010, negotiated timeout = 20000
[junit4:junit4]   2> 23789 T2028 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c84411b name:ZooKeeperConnection Watcher:127.0.0.1:33229/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 23789 T1904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 23790 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780010 type:create cxid:0x1 zxid:0xd7 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 23791 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780010 type:create cxid:0x2 zxid:0xd8 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 23792 T1904 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2>  C438_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:36270_um_xr, base_url=http://127.0.0.1:36270/um_xr}
[junit4:junit4]   2> 23948 T1997 C438 P36270 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:55383/um_xr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 23948 T1997 C438 P36270 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:36270/um_xr START replicas=[http://127.0.0.1:55383/um_xr/collection1/] nUpdates=100
[junit4:junit4]   2> 23949 T1997 C438 P36270 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 23949 T1997 C438 P36270 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 23950 T1997 C438 P36270 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 23950 T1997 C438 P36270 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 23950 T1997 C438 P36270 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 23951 T1997 C438 P36270 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:55383/um_xr/collection1/. core=collection1
[junit4:junit4]   2> 23951 T1997 C438 P36270 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C440 name=collection1 org.apache.solr.core.SolrCore@1c78e3ae url=http://127.0.0.1:55383/um_xr/collection1 node=127.0.0.1:55383_um_xr C440_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:55383_um_xr, base_url=http://127.0.0.1:55383/um_xr, leader=true}
[junit4:junit4]   2> 23954 T1940 C440 P55383 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0 
[junit4:junit4]   2> 23958 T1941 C440 P55383 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 23958 T1941 C440 P55383 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty1
[junit4:junit4]   2> 23960 T1941 C440 P55383 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty1/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 23960 T1941 C440 P55383 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 23966 T1941 C440 P55383 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty1/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty1/index,segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 23966 T1941 C440 P55383 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 23967 T1941 C440 P55383 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty1
[junit4:junit4]   2> 23967 T1941 C440 P55383 oass.SolrIndexSearcher.<init> Opening Searcher@1c930a9a realtime
[junit4:junit4]   2> 23967 T1941 C440 P55383 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 23968 T1941 C440 P55383 /update {waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 10
[junit4:junit4]   2> 23968 T1997 C438 P36270 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 23968 T1997 C438 P36270 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 23970 T1942 C440 P55383 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 23970 T1942 C440 P55383 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 23970 T1997 C438 P36270 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 23970 T1997 C438 P36270 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 23971 T1997 C438 P36270 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 23972 T1940 C440 P55383 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty1
[junit4:junit4]   2> 23973 T1940 C440 P55383 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty1/index
[junit4:junit4]   2> 23973 T1940 C440 P55383 REQ /replication {command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1 
[junit4:junit4]   2> 23974 T1997 C438 P36270 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 23974 T1997 C438 P36270 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4/index.20130305075020038 forceNew:false
[junit4:junit4]   2> 23975 T1997 C438 P36270 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4
[junit4:junit4]   2> 23975 T1997 C438 P36270 oash.SnapPuller.fetchLatestIndex Starting download to org.apache.lucene.store.MMapDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4/index.20130305075020038 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c93b295 fullCopy=false
[junit4:junit4]   2> 23977 T1941 C440 P55383 REQ /replication {file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
[junit4:junit4]   2> 23978 T1997 C438 P36270 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4/index
[junit4:junit4]   2> 23978 T1997 C438 P36270 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 23986 T1997 C438 P36270 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4
[junit4:junit4]   2> 23987 T1997 C438 P36270 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4
[junit4:junit4]   2> 23987 T1997 C438 P36270 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 23987 T1997 C438 P36270 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 23988 T1997 C438 P36270 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4
[junit4:junit4]   2> 23989 T1997 C438 P36270 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4/index,segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 23989 T1997 C438 P36270 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 23990 T1997 C438 P36270 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 23990 T1997 C438 P36270 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4
[junit4:junit4]   2> 23990 T1997 C438 P36270 oass.SolrIndexSearcher.<init> Opening Searcher@1c945650 main
[junit4:junit4]   2> 23991 T1996 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1c945650 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 23991 T1996 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4/index
[junit4:junit4]   2> 23992 T1997 C438 P36270 oash.SnapPuller.fetchLatestIndex removing temporary index download directory files org.apache.lucene.store.MMapDirectory@/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4/index.20130305075020038 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c93b295
[junit4:junit4]   2> 23992 T1997 C438 P36270 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4/index.20130305075020038
[junit4:junit4]   2> 23993 T1997 C438 P36270 oasc.CachingDirectoryFactory.close Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362466196085/jetty4/index
[junit4:junit4]   2> 23993 T1997 C438 P36270 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 23993 T1997 C438 P36270 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 23993 T1997 C438 P36270 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 23993 T1997 C438 P36270 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 23995 T1997 C438 P36270 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 24780 T1927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 24781 T1927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:44106_um_xr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:44106/um_xr"}
[junit4:junit4]   2> 24787 T1927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:36270_um_xr",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:36270/um_xr"}
[junit4:junit4]   2> 24806 T2028 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 24806 T2011 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 24806 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 24807 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 24806 T1994 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 24806 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 24806 T1962 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 24806 T1978 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 24807 T1904 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40861_um_xr
[junit4:junit4]   2> 24810 T1909 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d39504a780010 type:delete cxid:0xb zxid:0xe0 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:40861_um_xr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:40861_um_xr
[junit4:junit4]   2> 24811 T1904 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40861_um_xr
[junit4:junit4]   2> 24815 T2028 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 24815 T2011 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 24815 T1946 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 24816 T1994 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 24816 T1962 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 24816 T1926 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 24816 T1978 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 24817 T1962 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 24817 T1978 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 24818 T1933 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 24816 T1994 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 24818 T1933 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 24820 T1946 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 24820 T2028 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 24820 T2011 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 24821 T1926 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 24830 T2031 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1362466219740/collection1
[junit4:junit4]   2> 24831 T2031 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 24832 T2031 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 24832 T2031 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 24834 T2031 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1362466219740/collection1/'
[junit4:junit4]   2> 24835 T2031 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1362466219740/collection1/lib/README' to classloader
[junit4:junit4]   2> 24836 T2031 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1362466219740/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 24883 T2031 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 24923 T2031 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 24924 T2031 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 24929 T2031 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 25389 T2031 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 25395 T2031 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 25398 T2031 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 25411 T2031 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 25415 T2031 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 25419 T2031 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 25420 T2031 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 25420 T2031 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 25420 T2031 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 25421 T2031 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 25421 T2031 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 25422 T2031 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/work

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

it4]   2> 	        at org.apache.solr.cloud.ZkController.register(ZkController.java:766)
[junit4:junit4]   2> 	        at org.apache.solr.cloud.ZkController$1.command(ZkController.java:212)
[junit4:junit4]   2> 	        at org.apache.solr.common.cloud.ConnectionManager$1.update(ConnectionManager.java:117)
[junit4:junit4]   2> 	        at org.apache.solr.common.cloud.DefaultConnectionStrategy.reconnect(DefaultConnectionStrategy.java:46)
[junit4:junit4]   2> 	        at org.apache.solr.common.cloud.ConnectionManager.process(ConnectionManager.java:91)
[junit4:junit4]   2> 	        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4]   2> 	        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4]   2> 139957 T1903 ccr.ThreadLeakControl.tryToInterruptAll Starting to interrupt leaked threads:
[junit4:junit4]   2> 	   1) Thread[id=2123, name=TEST-ChaosMonkeySafeLeaderTest.testDistribSearch-seed#[E22BFD0C90735963]-EventThread, state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4]   2> 139957 T2123 oasc.ZkController.getLeader SEVERE Error getting leader from zk java.lang.InterruptedException: sleep interrupted
[junit4:junit4]   2> 	at java.lang.Thread.sleep(Native Method)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:428)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.ZkStateReader.getLeaderUrl(ZkStateReader.java:404)
[junit4:junit4]   2> 	at org.apache.solr.cloud.ZkController.getLeader(ZkController.java:833)
[junit4:junit4]   2> 	at org.apache.solr.cloud.ZkController.register(ZkController.java:766)
[junit4:junit4]   2> 	at org.apache.solr.cloud.ZkController$1.command(ZkController.java:212)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.ConnectionManager$1.update(ConnectionManager.java:117)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.DefaultConnectionStrategy.reconnect(DefaultConnectionStrategy.java:46)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.ConnectionManager.process(ConnectionManager.java:91)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4]   2> 
[junit4:junit4]   2> 139958 T2123 oasc.SolrException.log SEVERE Error registering SolrCore:org.apache.solr.common.SolrException: Error getting leader from zk
[junit4:junit4]   2> 		at org.apache.solr.cloud.ZkController.getLeader(ZkController.java:854)
[junit4:junit4]   2> 		at org.apache.solr.cloud.ZkController.register(ZkController.java:766)
[junit4:junit4]   2> 		at org.apache.solr.cloud.ZkController$1.command(ZkController.java:212)
[junit4:junit4]   2> 		at org.apache.solr.common.cloud.ConnectionManager$1.update(ConnectionManager.java:117)
[junit4:junit4]   2> 		at org.apache.solr.common.cloud.DefaultConnectionStrategy.reconnect(DefaultConnectionStrategy.java:48)
[junit4:junit4]   2> 		at org.apache.solr.common.cloud.ConnectionManager.process(ConnectionManager.java:91)
[junit4:junit4]   2> 		at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4]   2> 		at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4]   2> 	Caused by: java.lang.InterruptedException: sleep interrupted
[junit4:junit4]   2> 		at java.lang.Thread.sleep(Native Method)
[junit4:junit4]   2> 		at org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:428)
[junit4:junit4]   2> 		at org.apache.solr.common.cloud.ZkStateReader.getLeaderUrl(ZkStateReader.java:404)
[junit4:junit4]   2> 		at org.apache.solr.cloud.ZkController.getLeader(ZkController.java:833)
[junit4:junit4]   2> 		at org.apache.solr.cloud.ZkController.register(ZkController.java:766)
[junit4:junit4]   2> 		at org.apache.solr.cloud.ZkController$1.command(ZkController.java:212)
[junit4:junit4]   2> 		at org.apache.solr.common.cloud.ConnectionManager$1.update(ConnectionManager.java:117)
[junit4:junit4]   2> 		at org.apache.solr.common.cloud.DefaultConnectionStrategy.reconnect(DefaultConnectionStrategy.java:46)
[junit4:junit4]   2> 		... 3 more
[junit4:junit4]   2> 	
[junit4:junit4]   2> 139958 T2123 oascc.DefaultConnectionStrategy.reconnect Reconnected to ZooKeeper
[junit4:junit4]   2> 139959 T2123 oascc.ConnectionManager.process Connected:true
[junit4:junit4]   2> 139959 T2123 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 139959 T1903 ccr.ThreadLeakControl.tryToInterruptAll All leaked threads terminated.
[junit4:junit4]   2> NOTE: test params are: codec=Lucene42: {range_facet_l=PostingsFormat(name=MockSep), text=PostingsFormat(name=Memory doPackFST= false), _version_=PostingsFormat(name=MockSep), rnd_b=PostingsFormat(name=Asserting), intDefault=PostingsFormat(name=MockSep), id=PostingsFormat(name=Asserting), timestamp=PostingsFormat(name=MockSep), a_t=PostingsFormat(name=MockSep), range_facet_sl=PostingsFormat(name=Memory doPackFST= false), range_facet_si=MockFixedIntBlock(blockSize=477), other_tl1=PostingsFormat(name=MockSep), multiDefault=MockFixedIntBlock(blockSize=477), a_si=MockFixedIntBlock(blockSize=477)}, docValues:{timestamp=DocValuesFormat(name=Asserting)}, sim=DefaultSimilarity, locale=da_DK, timezone=Europe/Zurich
[junit4:junit4]   2> NOTE: Linux 3.2.0-38-generic amd64/Oracle Corporation 1.6.0_33 (64-bit)/cpus=8,threads=2,free=186482088,total=346308608
[junit4:junit4]   2> NOTE: All tests run in this JVM: [ClusterStateTest, TestArbitraryIndexDir, TestMergePolicyConfig, TestLMJelinekMercerSimilarityFactory, BadIndexSchemaTest, OpenCloseCoreStressTest, OutputWriterTest, CollectionsAPIDistributedZkTest, JSONWriterTest, LeaderElectionIntegrationTest, TestFastOutputStream, EchoParamsTest, TestCollationField, SolrPluginUtilsTest, SpellPossibilityIteratorTest, SolrIndexConfigTest, DirectUpdateHandlerTest, TestAnalyzedSuggestions, SortByFunctionTest, TestReload, OpenExchangeRatesOrgProviderTest, TestDistributedSearch, NumericFieldsTest, TestZkChroot, TestHashPartitioner, HighlighterTest, NotRequiredUniqueKeyTest, XsltUpdateRequestHandlerTest, DocValuesMultiTest, TestQueryTypes, HardAutoCommitTest, TestAtomicUpdateErrorCases, TestFoldingMultitermQuery, ConvertedLegacyTest, UniqFieldsUpdateProcessorFactoryTest, CurrencyFieldXmlFileTest, TestPropInject, IndexBasedSpellCheckerTest, CurrencyFieldOpenExchangeTest, TestOmitPositions, TestPartialUpdateDeduplication, DebugComponentTest, TermVectorComponentDistributedTest, RequestHandlersTest, RequiredFieldsTest, TestStressReorder, TestCSVLoader, TestUtils, DistanceFunctionTest, TestBinaryField, UpdateParamsTest, ChaosMonkeySafeLeaderTest]
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.seed=E22BFD0C90735963 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=da_DK -Dtests.timezone=Europe/Zurich -Dtests.file.encoding=US-ASCII
[junit4:junit4] ERROR   0.00s J1 | ChaosMonkeySafeLeaderTest (suite) <<<
[junit4:junit4]    > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest: 
[junit4:junit4]    >    1) Thread[id=2123, name=TEST-ChaosMonkeySafeLeaderTest.testDistribSearch-seed#[E22BFD0C90735963]-EventThread, state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4]    >         at java.lang.Thread.sleep(Native Method)
[junit4:junit4]    >         at org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:428)
[junit4:junit4]    >         at org.apache.solr.common.cloud.ZkStateReader.getLeaderUrl(ZkStateReader.java:404)
[junit4:junit4]    >         at org.apache.solr.cloud.ZkController.getLeader(ZkController.java:833)
[junit4:junit4]    >         at org.apache.solr.cloud.ZkController.register(ZkController.java:766)
[junit4:junit4]    >         at org.apache.solr.cloud.ZkController$1.command(ZkController.java:212)
[junit4:junit4]    >         at org.apache.solr.common.cloud.ConnectionManager$1.update(ConnectionManager.java:117)
[junit4:junit4]    >         at org.apache.solr.common.cloud.DefaultConnectionStrategy.reconnect(DefaultConnectionStrategy.java:46)
[junit4:junit4]    >         at org.apache.solr.common.cloud.ConnectionManager.process(ConnectionManager.java:91)
[junit4:junit4]    >         at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4]    >         at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([E22BFD0C90735963]:0)
[junit4:junit4] Completed on J1 in 140.03s, 1 test, 1 error <<< FAILURES!

[...truncated 466 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:381: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:361: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:183: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:449: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1213: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:877: There were test failures: 261 suites, 1105 tests, 1 suite-level error, 13 ignored (7 assumptions)

Total time: 91 minutes 33 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 64bit/jrockit-jdk1.6.0_33-R28.2.4-4.1.0 -XnoOpt
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message