You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/02/15 00:21:33 UTC
[JENKINS] Lucene-Solr-Tests-trunk-java7 - Build # 3734 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-java7/3734/
2 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch
Error Message:
Test abandoned because suite timeout was reached.
Stack Trace:
java.lang.Exception: Test abandoned because suite timeout was reached.
at __randomizedtesting.SeedInfo.seed([101AD7A038114CF6]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
Error Message:
Suite timeout exceeded (>= 7200000 msec).
Stack Trace:
java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
at __randomizedtesting.SeedInfo.seed([101AD7A038114CF6]:0)
Build Log:
[...truncated 9535 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4:junit4] 2> 0 T1529 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /cvk/hy
[junit4:junit4] 2> 6 T1529 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./solrtest-ChaosMonkeySafeLeaderTest-1360876848207
[junit4:junit4] 2> 7 T1529 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 7 T1530 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 10 T1530 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4] 2> 10 T1530 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4] 2> 10 T1530 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4] 2> 10 T1530 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> 11 T1530 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4] 2> 108 T1529 oasc.ZkTestServer.run start zk server on port:26209
[junit4:junit4] 2> 108 T1529 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26209 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@685f86a8
[junit4:junit4] 2> 109 T1529 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 109 T1535 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26209. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 110 T1535 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26209, initiating session
[junit4:junit4] 2> 110 T1531 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:18102
[junit4:junit4] 2> 111 T1531 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:18102
[junit4:junit4] 2> 111 T1533 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4] 2> 113 T1533 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cda94c4540000 with negotiated timeout 10000 for client /140.211.11.196:18102
[junit4:junit4] 2> 113 T1535 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26209, sessionid = 0x13cda94c4540000, negotiated timeout = 10000
[junit4:junit4] 2> 113 T1536 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@685f86a8 name:ZooKeeperConnection Watcher:127.0.0.1:26209 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 114 T1529 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 114 T1529 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 116 T1534 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cda94c4540000
[junit4:junit4] 2> 126 T1536 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 127 T1531 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:18102 which had sessionid 0x13cda94c4540000
[junit4:junit4] 2> 126 T1529 oaz.ZooKeeper.close Session: 0x13cda94c4540000 closed
[junit4:junit4] 2> 128 T1529 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26209/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@ac69af8
[junit4:junit4] 2> 128 T1529 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 128 T1537 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26209. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 129 T1537 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26209, initiating session
[junit4:junit4] 2> 129 T1531 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:25475
[junit4:junit4] 2> 129 T1531 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:25475
[junit4:junit4] 2> 130 T1533 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cda94c4540001 with negotiated timeout 10000 for client /140.211.11.196:25475
[junit4:junit4] 2> 130 T1537 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26209, sessionid = 0x13cda94c4540001, negotiated timeout = 10000
[junit4:junit4] 2> 131 T1538 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ac69af8 name:ZooKeeperConnection Watcher:127.0.0.1:26209/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 131 T1529 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 131 T1529 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 141 T1529 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 143 T1529 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 145 T1529 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 153 T1529 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 153 T1529 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 169 T1529 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 170 T1529 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 174 T1529 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 175 T1529 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 178 T1529 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 178 T1529 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 189 T1529 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 189 T1529 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 193 T1529 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 193 T1529 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 196 T1529 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 197 T1529 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 200 T1529 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 201 T1529 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 204 T1529 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 204 T1529 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 207 T1534 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cda94c4540001
[junit4:junit4] 2> 208 T1538 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 208 T1531 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:25475 which had sessionid 0x13cda94c4540001
[junit4:junit4] 2> 208 T1529 oaz.ZooKeeper.close Session: 0x13cda94c4540001 closed
[junit4:junit4] 2> 336 T1529 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 340 T1529 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:30864
[junit4:junit4] 2> 341 T1529 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 341 T1529 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 341 T1529 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1360876848410
[junit4:junit4] 2> 342 T1529 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1360876848410/solr.xml
[junit4:junit4] 2> 342 T1529 oasc.CoreContainer.<init> New CoreContainer 737516421
[junit4:junit4] 2> 343 T1529 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1360876848410/'
[junit4:junit4] 2> 343 T1529 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1360876848410/'
[junit4:junit4] 2> 390 T1529 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 391 T1529 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 391 T1529 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 392 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 392 T1529 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 392 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 393 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 393 T1529 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 393 T1529 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 394 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 411 T1529 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 426 T1529 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:26209/solr
[junit4:junit4] 2> 427 T1529 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 427 T1529 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26209 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@5f0ebab7
[junit4:junit4] 2> 428 T1529 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 428 T1548 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26209. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 429 T1548 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26209, initiating session
[junit4:junit4] 2> 429 T1531 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:28920
[junit4:junit4] 2> 429 T1531 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:28920
[junit4:junit4] 2> 438 T1533 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cda94c4540002 with negotiated timeout 20000 for client /140.211.11.196:28920
[junit4:junit4] 2> 438 T1548 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26209, sessionid = 0x13cda94c4540002, negotiated timeout = 20000
[junit4:junit4] 2> 438 T1549 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5f0ebab7 name:ZooKeeperConnection Watcher:127.0.0.1:26209 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 439 T1529 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 440 T1534 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cda94c4540002
[junit4:junit4] 2> 444 T1549 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 445 T1531 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:28920 which had sessionid 0x13cda94c4540002
[junit4:junit4] 2> 444 T1529 oaz.ZooKeeper.close Session: 0x13cda94c4540002 closed
[junit4:junit4] 2> 445 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 453 T1529 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26209/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@2938b01c
[junit4:junit4] 2> 454 T1529 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 454 T1550 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26209. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 454 T1550 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26209, initiating session
[junit4:junit4] 2> 455 T1531 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:49156
[junit4:junit4] 2> 455 T1531 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:49156
[junit4:junit4] 2> 461 T1533 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cda94c4540003 with negotiated timeout 20000 for client /140.211.11.196:49156
[junit4:junit4] 2> 461 T1550 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26209, sessionid = 0x13cda94c4540003, negotiated timeout = 20000
[junit4:junit4] 2> 462 T1551 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2938b01c name:ZooKeeperConnection Watcher:127.0.0.1:26209/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 462 T1529 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 473 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 481 T1529 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 483 T1529 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:30864_cvk%2Fhy
[junit4:junit4] 2> 484 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:30864_cvk%2Fhy Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:30864_cvk%2Fhy
[junit4:junit4] 2> 485 T1529 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:30864_cvk%2Fhy
[junit4:junit4] 2> 495 T1529 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 510 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540003 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> 520 T1529 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 522 T1529 oasc.Overseer.start Overseer (id=89186425124421635-127.0.0.1:30864_cvk%2Fhy-n_0000000000) starting
[junit4:junit4] 2> 522 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 523 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 524 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 525 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 526 T1553 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 526 T1529 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 528 T1529 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 529 T1552 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 533 T1554 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1360876848410/collection1
[junit4:junit4] 2> 533 T1554 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 534 T1554 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 534 T1554 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 535 T1554 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1360876848410/collection1/'
[junit4:junit4] 2> 536 T1554 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1360876848410/collection1/lib/README' to classloader
[junit4:junit4] 2> 536 T1554 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1360876848410/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 576 T1554 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 625 T1554 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 626 T1554 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 630 T1554 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 1042 T1554 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1049 T1554 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1052 T1554 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1064 T1554 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1068 T1554 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1071 T1554 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1072 T1554 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1073 T1554 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1360876848410/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/control/data/
[junit4:junit4] 2> 1073 T1554 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@25a75631
[junit4:junit4] 2> 1074 T1554 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 1096 T1554 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/control/data forceNew:false
[junit4:junit4] 2> 1097 T1554 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/control/data
[junit4:junit4] 2> 1097 T1554 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/control/data/index/
[junit4:junit4] 2> 1098 T1554 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1099 T1554 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/control/data/index forceNew:false
[junit4:junit4] 2> 1103 T1554 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@13f6e73e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 1103 T1554 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 1104 T1554 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/control/data/index
[junit4:junit4] 2> 1104 T1554 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 1105 T1554 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1105 T1554 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 1106 T1554 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1106 T1554 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 1106 T1554 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1107 T1554 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1107 T1554 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1107 T1554 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1108 T1554 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1108 T1554 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 1108 T1554 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 1109 T1554 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1109 T1554 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 1109 T1554 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 1109 T1554 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 1110 T1554 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1110 T1554 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1110 T1554 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1110 T1554 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1111 T1554 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1111 T1554 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1111 T1554 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1112 T1554 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1112 T1554 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1112 T1554 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 1113 T1554 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 1121 T1554 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1124 T1554 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 1125 T1554 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 1127 T1554 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/control/data
[junit4:junit4] 2> 1128 T1554 oass.SolrIndexSearcher.<init> Opening Searcher@6144eaf8 main
[junit4:junit4] 2> 1129 T1554 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1129 T1554 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1129 T1554 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 1144 T1554 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 1193 T1555 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6144eaf8 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1195 T1554 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1195 T1554 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1196 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540003 type:create cxid:0x51 zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4] 2> 2032 T1552 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2033 T1552 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[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:30864_cvk%2Fhy",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:30864/cvk/hy"}
[junit4:junit4] 2> 2033 T1552 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 2034 T1552 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 2034 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540003 type:create cxid:0x59 zxid:0x2c txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4] 2> 2050 T1551 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> 2208 T1554 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2208 T1554 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:30864/cvk/hy collection:control_collection shard:shard1
[junit4:junit4] 2> 2209 T1554 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2226 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540003 type:delete cxid:0x73 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> 2234 T1554 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2235 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540003 type:create cxid:0x74 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 2237 T1554 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2237 T1554 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2238 T1554 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:30864/cvk/hy/collection1/
[junit4:junit4] 2> 2238 T1554 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2238 T1554 oasc.SyncStrategy.syncToMe http://127.0.0.1:30864/cvk/hy/collection1/ has no replicas
[junit4:junit4] 2> 2239 T1554 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:30864/cvk/hy/collection1/
[junit4:junit4] 2> 2239 T1554 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 2249 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540003 type:create cxid:0x7e zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3555 T1552 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3575 T1551 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> 3637 T1554 oasc.ZkController.register We are http://127.0.0.1:30864/cvk/hy/collection1/ and leader is http://127.0.0.1:30864/cvk/hy/collection1/
[junit4:junit4] 2> 3637 T1554 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:30864/cvk/hy
[junit4:junit4] 2> 3637 T1554 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 3638 T1554 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 3638 T1554 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 3640 T1554 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3641 T1529 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0
[junit4:junit4] 2> 3642 T1529 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 3642 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 3657 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 3658 T1529 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26209/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@39fcacb2
[junit4:junit4] 2> 3659 T1529 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3659 T1556 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26209. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3660 T1556 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26209, initiating session
[junit4:junit4] 2> 3660 T1531 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:51032
[junit4:junit4] 2> 3660 T1531 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:51032
[junit4:junit4] 2> 3661 T1533 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cda94c4540004 with negotiated timeout 10000 for client /140.211.11.196:51032
[junit4:junit4] 2> 3661 T1556 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26209, sessionid = 0x13cda94c4540004, negotiated timeout = 10000
[junit4:junit4] 2> 3662 T1557 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@39fcacb2 name:ZooKeeperConnection Watcher:127.0.0.1:26209/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3662 T1529 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3664 T1529 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 3665 T1529 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 3835 T1529 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 3837 T1529 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:21009
[junit4:junit4] 2> 3838 T1529 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 3839 T1529 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 3839 T1529 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1360876851867
[junit4:junit4] 2> 3840 T1529 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1360876851867/solr.xml
[junit4:junit4] 2> 3840 T1529 oasc.CoreContainer.<init> New CoreContainer 1198671981
[junit4:junit4] 2> 3841 T1529 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1360876851867/'
[junit4:junit4] 2> 3841 T1529 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1360876851867/'
[junit4:junit4] 2> 3901 T1529 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 3902 T1529 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 3903 T1529 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 3903 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 3904 T1529 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 3904 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 3904 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 3905 T1529 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 3905 T1529 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 3906 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 3926 T1529 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 3945 T1529 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:26209/solr
[junit4:junit4] 2> 3946 T1529 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 3946 T1529 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26209 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@ed3498d
[junit4:junit4] 2> 3948 T1529 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3948 T1567 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26209. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3949 T1567 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26209, initiating session
[junit4:junit4] 2> 3949 T1531 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:25834
[junit4:junit4] 2> 3949 T1531 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:25834
[junit4:junit4] 2> 3951 T1533 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cda94c4540005 with negotiated timeout 20000 for client /140.211.11.196:25834
[junit4:junit4] 2> 3951 T1567 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26209, sessionid = 0x13cda94c4540005, negotiated timeout = 20000
[junit4:junit4] 2> 3952 T1568 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ed3498d name:ZooKeeperConnection Watcher:127.0.0.1:26209 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3952 T1529 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3953 T1534 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cda94c4540005
[junit4:junit4] 2> 3960 T1568 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 3961 T1531 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:25834 which had sessionid 0x13cda94c4540005
[junit4:junit4] 2> 3960 T1529 oaz.ZooKeeper.close Session: 0x13cda94c4540005 closed
[junit4:junit4] 2> 3961 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 3971 T1529 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26209/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1271c384
[junit4:junit4] 2> 3972 T1529 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 3973 T1569 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26209. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 3973 T1569 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26209, initiating session
[junit4:junit4] 2> 3973 T1531 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:41658
[junit4:junit4] 2> 3974 T1531 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:41658
[junit4:junit4] 2> 3975 T1533 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cda94c4540006 with negotiated timeout 20000 for client /140.211.11.196:41658
[junit4:junit4] 2> 3975 T1569 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26209, sessionid = 0x13cda94c4540006, negotiated timeout = 20000
[junit4:junit4] 2> 3975 T1570 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1271c384 name:ZooKeeperConnection Watcher:127.0.0.1:26209/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 3976 T1529 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 3977 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540006 type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3979 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540006 type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3986 T1529 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 3988 T1529 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:21009_cvk%2Fhy
[junit4:junit4] 2> 3989 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540006 type:delete cxid:0x9 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:21009_cvk%2Fhy Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:21009_cvk%2Fhy
[junit4:junit4] 2> 3990 T1529 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:21009_cvk%2Fhy
[junit4:junit4] 2> 3998 T1551 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> 3998 T1570 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 3998 T1557 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 3999 T1551 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 4006 T1571 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1360876851867/collection1
[junit4:junit4] 2> 4006 T1571 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 4007 T1571 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 4007 T1571 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 4008 T1571 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1360876851867/collection1/'
[junit4:junit4] 2> 4010 T1571 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1360876851867/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 4010 T1571 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1360876851867/collection1/lib/README' to classloader
[junit4:junit4] 2> 4066 T1571 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 4138 T1571 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 4140 T1571 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 4146 T1571 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 4842 T1571 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 4857 T1571 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 4862 T1571 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 4876 T1571 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 4880 T1571 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 4885 T1571 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 4887 T1571 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 4889 T1571 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1360876851867/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty1/
[junit4:junit4] 2> 4890 T1571 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@25a75631
[junit4:junit4] 2> 4890 T1571 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 4892 T1571 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty1 forceNew:false
[junit4:junit4] 2> 4893 T1571 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty1
[junit4:junit4] 2> 4893 T1571 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty1/index/
[junit4:junit4] 2> 4894 T1571 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 4924 T1571 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty1/index forceNew:false
[junit4:junit4] 2> 4930 T1571 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1dfdcae5),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 4930 T1571 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 4931 T1571 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty1/index
[junit4:junit4] 2> 4932 T1571 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 4934 T1571 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 4934 T1571 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 4934 T1571 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 4935 T1571 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 4935 T1571 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 4936 T1571 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 4936 T1571 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 4937 T1571 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 4937 T1571 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 4938 T1571 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 4938 T1571 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 4939 T1571 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 4939 T1571 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 4940 T1571 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 4940 T1571 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 4941 T1571 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 4941 T1571 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 4942 T1571 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 4942 T1571 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 4943 T1571 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 4943 T1571 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 4944 T1571 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 4944 T1571 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 4945 T1571 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 4945 T1571 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 4946 T1571 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 4962 T1571 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 4967 T1571 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 4969 T1571 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 4971 T1571 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty1
[junit4:junit4] 2> 4973 T1571 oass.SolrIndexSearcher.<init> Opening Searcher@684c4913 main
[junit4:junit4] 2> 4974 T1571 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 4975 T1571 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 4975 T1571 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 4983 T1571 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 5037 T1572 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@684c4913 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 5042 T1571 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 5042 T1571 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 5087 T1552 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 5088 T1552 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[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:30864_cvk%2Fhy",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:30864/cvk/hy"}
[junit4:junit4] 2> 5092 T1552 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[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:21009_cvk%2Fhy",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:21009/cvk/hy"}
[junit4:junit4] 2> 5093 T1552 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 3
[junit4:junit4] 2> 5093 T1552 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 5104 T1570 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> 5104 T1551 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> 5104 T1557 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> 6044 T1571 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 6044 T1571 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:21009/cvk/hy collection:collection1 shard:shard1
[junit4:junit4] 2> 6045 T1571 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 6062 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540006 type:delete cxid:0x45 zxid:0x5a txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4] 2> 6063 T1571 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 6063 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540006 type:create cxid:0x46 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 6073 T1571 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 6073 T1571 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 6073 T1571 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:21009/cvk/hy/collection1/
[junit4:junit4] 2> 6074 T1571 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 6074 T1571 oasc.SyncStrategy.syncToMe http://127.0.0.1:21009/cvk/hy/collection1/ has no replicas
[junit4:junit4] 2> 6074 T1571 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:21009/cvk/hy/collection1/
[junit4:junit4] 2> 6074 T1571 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 6084 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540006 type:create cxid:0x50 zxid:0x5f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 6617 T1552 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 6635 T1551 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> 6635 T1557 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> 6635 T1570 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> 6647 T1571 oasc.ZkController.register We are http://127.0.0.1:21009/cvk/hy/collection1/ and leader is http://127.0.0.1:21009/cvk/hy/collection1/
[junit4:junit4] 2> 6647 T1571 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:21009/cvk/hy
[junit4:junit4] 2> 6647 T1571 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 6648 T1571 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 6648 T1571 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 6662 T1571 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 6663 T1529 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0
[junit4:junit4] 2> 6664 T1529 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 6664 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 6928 T1529 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 6932 T1529 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:64869
[junit4:junit4] 2> 6933 T1529 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 6933 T1529 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 6934 T1529 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1360876854880
[junit4:junit4] 2> 6934 T1529 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1360876854880/solr.xml
[junit4:junit4] 2> 6935 T1529 oasc.CoreContainer.<init> New CoreContainer 462915659
[junit4:junit4] 2> 6935 T1529 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1360876854880/'
[junit4:junit4] 2> 6936 T1529 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1360876854880/'
[junit4:junit4] 2> 6996 T1529 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 6996 T1529 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 6997 T1529 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 6997 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 6998 T1529 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 6998 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 6999 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 6999 T1529 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 7000 T1529 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 7000 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 7022 T1529 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 7042 T1529 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:26209/solr
[junit4:junit4] 2> 7043 T1529 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 7043 T1529 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26209 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@78b57855
[junit4:junit4] 2> 7044 T1529 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 7045 T1582 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26209. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 7046 T1582 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26209, initiating session
[junit4:junit4] 2> 7046 T1531 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:65006
[junit4:junit4] 2> 7047 T1531 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:65006
[junit4:junit4] 2> 7048 T1533 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cda94c4540007 with negotiated timeout 20000 for client /140.211.11.196:65006
[junit4:junit4] 2> 7048 T1582 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26209, sessionid = 0x13cda94c4540007, negotiated timeout = 20000
[junit4:junit4] 2> 7049 T1583 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@78b57855 name:ZooKeeperConnection Watcher:127.0.0.1:26209 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 7049 T1529 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 7051 T1534 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cda94c4540007
[junit4:junit4] 2> 7052 T1583 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 7052 T1531 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:65006 which had sessionid 0x13cda94c4540007
[junit4:junit4] 2> 7052 T1529 oaz.ZooKeeper.close Session: 0x13cda94c4540007 closed
[junit4:junit4] 2> 7053 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 7065 T1529 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26209/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@6a2d4645
[junit4:junit4] 2> 7066 T1529 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 7066 T1584 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26209. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 7067 T1584 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26209, initiating session
[junit4:junit4] 2> 7067 T1531 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:46781
[junit4:junit4] 2> 7067 T1531 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:46781
[junit4:junit4] 2> 7069 T1533 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cda94c4540008 with negotiated timeout 20000 for client /140.211.11.196:46781
[junit4:junit4] 2> 7069 T1584 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26209, sessionid = 0x13cda94c4540008, negotiated timeout = 20000
[junit4:junit4] 2> 7069 T1585 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6a2d4645 name:ZooKeeperConnection Watcher:127.0.0.1:26209/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 7069 T1529 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 7070 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540008 type:create cxid:0x1 zxid:0x6c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 7072 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540008 type:create cxid:0x2 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 7080 T1529 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 7082 T1529 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64869_cvk%2Fhy
[junit4:junit4] 2> 7083 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540008 type:delete cxid:0x9 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:64869_cvk%2Fhy Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:64869_cvk%2Fhy
[junit4:junit4] 2> 7084 T1529 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:64869_cvk%2Fhy
[junit4:junit4] 2> 7087 T1557 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> 7087 T1551 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> 7088 T1570 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 7088 T1585 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 7088 T1570 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> 7089 T1557 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 7089 T1551 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 7101 T1586 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1360876854880/collection1
[junit4:junit4] 2> 7101 T1586 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 7102 T1586 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 7102 T1586 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 7104 T1586 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1360876854880/collection1/'
[junit4:junit4] 2> 7105 T1586 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1360876854880/collection1/lib/README' to classloader
[junit4:junit4] 2> 7105 T1586 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1360876854880/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 7163 T1586 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 7240 T1586 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 7241 T1586 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 7247 T1586 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 7900 T1586 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 7911 T1586 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 7916 T1586 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 7931 T1586 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 7937 T1586 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 7942 T1586 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 7943 T1586 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 7944 T1586 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1360876854880/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty2/
[junit4:junit4] 2> 7944 T1586 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@25a75631
[junit4:junit4] 2> 7945 T1586 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 7946 T1586 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty2 forceNew:false
[junit4:junit4] 2> 7946 T1586 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty2
[junit4:junit4] 2> 7947 T1586 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty2/index/
[junit4:junit4] 2> 7947 T1586 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 7949 T1586 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty2/index forceNew:false
[junit4:junit4] 2> 7961 T1586 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@6714453c),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 7962 T1586 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 7962 T1586 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty2/index
[junit4:junit4] 2> 7963 T1586 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 7965 T1586 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 7965 T1586 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 7965 T1586 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 7966 T1586 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 7966 T1586 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 7967 T1586 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 7967 T1586 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 7968 T1586 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 7968 T1586 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 7969 T1586 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 7969 T1586 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 7970 T1586 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 7970 T1586 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 7970 T1586 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 7971 T1586 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 7971 T1586 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 7972 T1586 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 7972 T1586 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 7973 T1586 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 7973 T1586 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 7974 T1586 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 7975 T1586 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 7975 T1586 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 7976 T1586 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 7976 T1586 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 7977 T1586 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 7989 T1586 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 7994 T1586 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 7995 T1586 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 7997 T1586 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty2
[junit4:junit4] 2> 7999 T1586 oass.SolrIndexSearcher.<init> Opening Searcher@3102f772 main
[junit4:junit4] 2> 8000 T1586 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 8000 T1586 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 8001 T1586 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 8012 T1586 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 8055 T1587 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3102f772 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 8059 T1586 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 8060 T1586 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 8149 T1552 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8150 T1552 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[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:21009_cvk%2Fhy",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:21009/cvk/hy"}
[junit4:junit4] 2> 8155 T1552 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[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:64869_cvk%2Fhy",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:64869/cvk/hy"}
[junit4:junit4] 2> 8155 T1552 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 8155 T1552 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 8166 T1570 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> 8166 T1585 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> 8166 T1551 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> 8166 T1557 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> 9063 T1586 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 9063 T1586 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:64869/cvk/hy collection:collection1 shard:shard2
[junit4:junit4] 2> 9064 T1586 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 9096 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540008 type:delete cxid:0x44 zxid:0x7c txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard2 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard2
[junit4:junit4] 2> 9107 T1586 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 9107 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540008 type:create cxid:0x45 zxid:0x7d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 9110 T1586 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 9110 T1586 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 9110 T1586 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:64869/cvk/hy/collection1/
[junit4:junit4] 2> 9110 T1586 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 9111 T1586 oasc.SyncStrategy.syncToMe http://127.0.0.1:64869/cvk/hy/collection1/ has no replicas
[junit4:junit4] 2> 9111 T1586 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:64869/cvk/hy/collection1/
[junit4:junit4] 2> 9111 T1586 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 9114 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540008 type:create cxid:0x4e zxid:0x80 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 9680 T1552 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 9700 T1570 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> 9700 T1557 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> 9700 T1585 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> 9700 T1551 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> 9728 T1586 oasc.ZkController.register We are http://127.0.0.1:64869/cvk/hy/collection1/ and leader is http://127.0.0.1:64869/cvk/hy/collection1/
[junit4:junit4] 2> 9728 T1586 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:64869/cvk/hy
[junit4:junit4] 2> 9728 T1586 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 9728 T1586 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 9729 T1586 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 9730 T1586 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 9731 T1529 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0
[junit4:junit4] 2> 9732 T1529 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 9732 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 9915 T1529 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 9918 T1529 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:19691
[junit4:junit4] 2> 9919 T1529 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 9920 T1529 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 9920 T1529 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1360876857948
[junit4:junit4] 2> 9921 T1529 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1360876857948/solr.xml
[junit4:junit4] 2> 9921 T1529 oasc.CoreContainer.<init> New CoreContainer 1268542239
[junit4:junit4] 2> 9922 T1529 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1360876857948/'
[junit4:junit4] 2> 9922 T1529 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1360876857948/'
[junit4:junit4] 2> 9984 T1529 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 9985 T1529 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 9986 T1529 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 9986 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 9987 T1529 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 9987 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 9988 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 9988 T1529 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 9989 T1529 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 9989 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 10009 T1529 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 10030 T1529 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:26209/solr
[junit4:junit4] 2> 10030 T1529 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 10031 T1529 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26209 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@2faefe71
[junit4:junit4] 2> 10032 T1529 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 10032 T1597 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26209. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 10033 T1597 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26209, initiating session
[junit4:junit4] 2> 10033 T1531 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:41973
[junit4:junit4] 2> 10034 T1531 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:41973
[junit4:junit4] 2> 10036 T1533 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cda94c4540009 with negotiated timeout 20000 for client /140.211.11.196:41973
[junit4:junit4] 2> 10036 T1597 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26209, sessionid = 0x13cda94c4540009, negotiated timeout = 20000
[junit4:junit4] 2> 10036 T1598 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2faefe71 name:ZooKeeperConnection Watcher:127.0.0.1:26209 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 10037 T1529 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 10038 T1534 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cda94c4540009
[junit4:junit4] 2> 10048 T1598 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 10048 T1531 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:41973 which had sessionid 0x13cda94c4540009
[junit4:junit4] 2> 10048 T1529 oaz.ZooKeeper.close Session: 0x13cda94c4540009 closed
[junit4:junit4] 2> 10049 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 10059 T1529 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26209/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@69795045
[junit4:junit4] 2> 10060 T1529 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 10060 T1599 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26209. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 10061 T1599 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26209, initiating session
[junit4:junit4] 2> 10061 T1531 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:31474
[junit4:junit4] 2> 10061 T1531 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:31474
[junit4:junit4] 2> 10063 T1533 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cda94c454000a with negotiated timeout 20000 for client /140.211.11.196:31474
[junit4:junit4] 2> 10063 T1599 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26209, sessionid = 0x13cda94c454000a, negotiated timeout = 20000
[junit4:junit4] 2> 10063 T1600 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@69795045 name:ZooKeeperConnection Watcher:127.0.0.1:26209/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 10063 T1529 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 10065 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c454000a type:create cxid:0x1 zxid:0x8d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 10066 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c454000a type:create cxid:0x2 zxid:0x8e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 10068 T1529 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 10070 T1529 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:19691_cvk%2Fhy
[junit4:junit4] 2> 10071 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c454000a type:delete cxid:0x9 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:19691_cvk%2Fhy Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:19691_cvk%2Fhy
[junit4:junit4] 2> 10072 T1529 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:19691_cvk%2Fhy
[junit4:junit4] 2> 10080 T1551 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> 10081 T1557 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> 10081 T1585 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> 10081 T1600 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 10081 T1570 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 10082 T1570 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> 10083 T1557 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 10083 T1551 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 10084 T1585 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 10090 T1601 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1360876857948/collection1
[junit4:junit4] 2> 10090 T1601 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 10091 T1601 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 10091 T1601 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 10092 T1601 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1360876857948/collection1/'
[junit4:junit4] 2> 10094 T1601 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1360876857948/collection1/lib/README' to classloader
[junit4:junit4] 2> 10094 T1601 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1360876857948/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 10151 T1601 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 10225 T1601 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 10226 T1601 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 10233 T1601 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 10813 T1601 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 10820 T1601 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 10823 T1601 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 10834 T1601 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 10838 T1601 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 10841 T1601 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 10842 T1601 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 10843 T1601 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1360876857948/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty3/
[junit4:junit4] 2> 10843 T1601 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@25a75631
[junit4:junit4] 2> 10843 T1601 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 10844 T1601 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty3 forceNew:false
[junit4:junit4] 2> 10844 T1601 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty3
[junit4:junit4] 2> 10845 T1601 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty3/index/
[junit4:junit4] 2> 10845 T1601 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 10846 T1601 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty3/index forceNew:false
[junit4:junit4] 2> 10850 T1601 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@46193488),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 10851 T1601 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 10851 T1601 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty3/index
[junit4:junit4] 2> 10852 T1601 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 10853 T1601 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 10853 T1601 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 10853 T1601 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 10854 T1601 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 10854 T1601 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 10854 T1601 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 10855 T1601 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 10855 T1601 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 10855 T1601 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 10856 T1601 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 10856 T1601 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 10856 T1601 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 10857 T1601 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 10857 T1601 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 10857 T1601 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 10858 T1601 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 10858 T1601 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10858 T1601 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10859 T1601 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10859 T1601 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10859 T1601 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10860 T1601 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10860 T1601 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10860 T1601 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10861 T1601 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 10861 T1601 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 10869 T1601 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 10872 T1601 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 10873 T1601 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 10875 T1601 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty3
[junit4:junit4] 2> 10876 T1601 oass.SolrIndexSearcher.<init> Opening Searcher@4b1bd106 main
[junit4:junit4] 2> 10877 T1601 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 10877 T1601 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 10877 T1601 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 10882 T1601 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 10929 T1602 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4b1bd106 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 10932 T1601 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 10932 T1601 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 11213 T1552 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 11214 T1552 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[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:64869_cvk%2Fhy",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:64869/cvk/hy"}
[junit4:junit4] 2> 11217 T1552 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[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:19691_cvk%2Fhy",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:19691/cvk/hy"}
[junit4:junit4] 2> 11218 T1552 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 11218 T1552 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4:junit4] 2> 11244 T1570 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> 11244 T1551 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> 11244 T1557 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> 11244 T1585 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> 11244 T1600 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> 11934 T1601 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 11934 T1601 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:19691/cvk/hy collection:collection1 shard:shard3
[junit4:junit4] 2> 11935 T1601 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4:junit4] 2> 11974 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c454000a type:delete cxid:0x44 zxid:0x9d txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard3 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard3
[junit4:junit4] 2> 11975 T1601 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 11976 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c454000a type:create cxid:0x45 zxid:0x9e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 11978 T1601 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 11979 T1601 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 11979 T1601 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:19691/cvk/hy/collection1/
[junit4:junit4] 2> 11979 T1601 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 11980 T1601 oasc.SyncStrategy.syncToMe http://127.0.0.1:19691/cvk/hy/collection1/ has no replicas
[junit4:junit4] 2> 11980 T1601 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:19691/cvk/hy/collection1/
[junit4:junit4] 2> 11980 T1601 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4:junit4] 2> 11984 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c454000a type:create cxid:0x4e zxid:0xa1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 12757 T1552 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 12810 T1570 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> 12810 T1585 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> 12810 T1600 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> 12810 T1557 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> 12810 T1551 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> 12858 T1601 oasc.ZkController.register We are http://127.0.0.1:19691/cvk/hy/collection1/ and leader is http://127.0.0.1:19691/cvk/hy/collection1/
[junit4:junit4] 2> 12858 T1601 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:19691/cvk/hy
[junit4:junit4] 2> 12858 T1601 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 12858 T1601 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 12859 T1601 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 12862 T1601 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 12863 T1529 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0
[junit4:junit4] 2> 12864 T1529 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 12864 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 13069 T1529 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 13072 T1529 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:27189
[junit4:junit4] 2> 13073 T1529 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 13074 T1529 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 13074 T1529 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1360876861081
[junit4:junit4] 2> 13075 T1529 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1360876861081/solr.xml
[junit4:junit4] 2> 13075 T1529 oasc.CoreContainer.<init> New CoreContainer 538076653
[junit4:junit4] 2> 13076 T1529 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1360876861081/'
[junit4:junit4] 2> 13076 T1529 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1360876861081/'
[junit4:junit4] 2> 13143 T1529 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 13144 T1529 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 13144 T1529 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 13144 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 13145 T1529 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 13145 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 13146 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 13146 T1529 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 13147 T1529 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 13147 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 13169 T1529 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 13209 T1529 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:26209/solr
[junit4:junit4] 2> 13210 T1529 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 13210 T1529 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26209 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@38b05b3b
[junit4:junit4] 2> 13212 T1529 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 13212 T1612 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26209. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 13213 T1612 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26209, initiating session
[junit4:junit4] 2> 13213 T1531 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:59719
[junit4:junit4] 2> 13214 T1531 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:59719
[junit4:junit4] 2> 13216 T1533 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cda94c454000b with negotiated timeout 20000 for client /140.211.11.196:59719
[junit4:junit4] 2> 13216 T1612 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26209, sessionid = 0x13cda94c454000b, negotiated timeout = 20000
[junit4:junit4] 2> 13216 T1613 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@38b05b3b name:ZooKeeperConnection Watcher:127.0.0.1:26209 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 13216 T1529 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 13218 T1534 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cda94c454000b
[junit4:junit4] 2> 13220 T1613 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 13220 T1531 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:59719 which had sessionid 0x13cda94c454000b
[junit4:junit4] 2> 13220 T1529 oaz.ZooKeeper.close Session: 0x13cda94c454000b closed
[junit4:junit4] 2> 13221 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 13233 T1529 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26209/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@5495bc1e
[junit4:junit4] 2> 13234 T1529 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 13234 T1614 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26209. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 13235 T1614 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26209, initiating session
[junit4:junit4] 2> 13235 T1531 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:28685
[junit4:junit4] 2> 13236 T1531 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:28685
[junit4:junit4] 2> 13237 T1533 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cda94c454000c with negotiated timeout 20000 for client /140.211.11.196:28685
[junit4:junit4] 2> 13237 T1614 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26209, sessionid = 0x13cda94c454000c, negotiated timeout = 20000
[junit4:junit4] 2> 13238 T1615 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5495bc1e name:ZooKeeperConnection Watcher:127.0.0.1:26209/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 13238 T1529 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 13239 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c454000c type:create cxid:0x1 zxid:0xae txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13241 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c454000c type:create cxid:0x2 zxid:0xaf txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13249 T1529 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 13251 T1529 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:27189_cvk%2Fhy
[junit4:junit4] 2> 13252 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c454000c type:delete cxid:0x9 zxid:0xb0 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:27189_cvk%2Fhy Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:27189_cvk%2Fhy
[junit4:junit4] 2> 13253 T1529 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:27189_cvk%2Fhy
[junit4:junit4] 2> 13257 T1557 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> 13257 T1551 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> 13257 T1585 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> 13258 T1615 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 13261 T1570 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 13262 T1570 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> 13262 T1600 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 13262 T1600 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> 13266 T1585 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 13267 T1557 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 13267 T1551 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 13278 T1616 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1360876861081/collection1
[junit4:junit4] 2> 13278 T1616 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 13279 T1616 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 13279 T1616 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 13280 T1616 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1360876861081/collection1/'
[junit4:junit4] 2> 13282 T1616 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1360876861081/collection1/lib/README' to classloader
[junit4:junit4] 2> 13282 T1616 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1360876861081/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 13352 T1616 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 13425 T1616 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 13427 T1616 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 13433 T1616 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 14074 T1616 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 14085 T1616 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 14089 T1616 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 14103 T1616 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 14108 T1616 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 14113 T1616 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 14114 T1616 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 14115 T1616 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1360876861081/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty4/
[junit4:junit4] 2> 14115 T1616 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@25a75631
[junit4:junit4] 2> 14116 T1616 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 14117 T1616 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty4 forceNew:false
[junit4:junit4] 2> 14117 T1616 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty4
[junit4:junit4] 2> 14118 T1616 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty4/index/
[junit4:junit4] 2> 14118 T1616 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 14120 T1616 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty4/index forceNew:false
[junit4:junit4] 2> 14132 T1616 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@6fab4919),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 14132 T1616 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 14133 T1616 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty4/index
[junit4:junit4] 2> 14133 T1616 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 14135 T1616 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 14136 T1616 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 14136 T1616 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 14136 T1616 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 14137 T1616 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 14137 T1616 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 14138 T1616 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 14138 T1616 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 14139 T1616 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 14139 T1616 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 14140 T1616 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 14140 T1616 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 14141 T1616 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 14141 T1616 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 14141 T1616 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 14142 T1616 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 14143 T1616 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 14143 T1616 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 14144 T1616 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 14144 T1616 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 14145 T1616 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 14145 T1616 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 14146 T1616 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 14146 T1616 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 14147 T1616 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 14147 T1616 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 14160 T1616 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 14164 T1616 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 14165 T1616 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 14168 T1616 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty4
[junit4:junit4] 2> 14169 T1616 oass.SolrIndexSearcher.<init> Opening Searcher@59ef2d41 main
[junit4:junit4] 2> 14170 T1616 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 14171 T1616 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 14171 T1616 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 14186 T1616 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 14260 T1617 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@59ef2d41 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 14264 T1616 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 14265 T1616 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 14324 T1552 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 14325 T1552 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[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:19691_cvk%2Fhy",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:19691/cvk/hy"}
[junit4:junit4] 2> 14329 T1552 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[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:27189_cvk%2Fhy",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:27189/cvk/hy"}
[junit4:junit4] 2> 14330 T1552 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 14330 T1552 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 14341 T1600 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> 14341 T1615 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> 14341 T1551 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> 14341 T1557 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> 14341 T1585 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> 14341 T1570 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> 15267 T1616 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 15267 T1616 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:27189/cvk/hy collection:collection1 shard:shard1
[junit4:junit4] 2> 15273 T1616 oasc.ZkController.register We are http://127.0.0.1:27189/cvk/hy/collection1/ and leader is http://127.0.0.1:21009/cvk/hy/collection1/
[junit4:junit4] 2> 15273 T1616 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:27189/cvk/hy
[junit4:junit4] 2> 15273 T1616 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 15273 T1616 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C90 name=collection1 org.apache.solr.core.SolrCore@5c195dc3 url=http://127.0.0.1:27189/cvk/hy/collection1 node=127.0.0.1:27189_cvk%2Fhy C90_STATE=coll:collection1 core:collection1 props:{shard=null, roles=null, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:27189_cvk%2Fhy, base_url=http://127.0.0.1:27189/cvk/hy}
[junit4:junit4] 2> 15276 T1619 C90 P27189 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 15276 T1616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 15276 T1619 C90 P27189 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 15277 T1619 C90 P27189 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 15277 T1619 C90 P27189 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 15277 T1529 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0
[junit4:junit4] 2> 15278 T1529 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 15279 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 15280 T1619 C90 P27189 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 15463 T1529 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 15466 T1529 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:15529
[junit4:junit4] 2> 15467 T1529 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 15467 T1529 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 15468 T1529 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1360876863498
[junit4:junit4] 2> 15468 T1529 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1360876863498/solr.xml
[junit4:junit4] 2> 15469 T1529 oasc.CoreContainer.<init> New CoreContainer 585015694
[junit4:junit4] 2> 15469 T1529 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1360876863498/'
[junit4:junit4] 2> 15470 T1529 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1360876863498/'
[junit4:junit4] 2> 15530 T1529 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 15531 T1529 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 15531 T1529 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 15532 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 15532 T1529 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 15533 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 15533 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 15534 T1529 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 15534 T1529 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 15535 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 15556 T1529 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 15576 T1529 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:26209/solr
[junit4:junit4] 2> 15577 T1529 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 15577 T1529 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26209 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@5fda8075
[junit4:junit4] 2> 15579 T1529 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 15579 T1629 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26209. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 15580 T1629 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26209, initiating session
[junit4:junit4] 2> 15580 T1531 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:15530
[junit4:junit4] 2> 15581 T1531 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:15530
[junit4:junit4] 2> 15582 T1533 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cda94c454000d with negotiated timeout 20000 for client /140.211.11.196:15530
[junit4:junit4] 2> 15582 T1629 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26209, sessionid = 0x13cda94c454000d, negotiated timeout = 20000
[junit4:junit4] 2> 15583 T1630 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5fda8075 name:ZooKeeperConnection Watcher:127.0.0.1:26209 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 15583 T1529 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 15585 T1534 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cda94c454000d
[junit4:junit4] 2> 15586 T1531 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:15530 which had sessionid 0x13cda94c454000d
[junit4:junit4] 2> 15586 T1630 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 15586 T1529 oaz.ZooKeeper.close Session: 0x13cda94c454000d closed
[junit4:junit4] 2> 15587 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 15600 T1529 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26209/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1375d753
[junit4:junit4] 2> 15601 T1529 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 15601 T1631 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26209. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 15602 T1631 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26209, initiating session
[junit4:junit4] 2> 15602 T1531 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:15531
[junit4:junit4] 2> 15602 T1531 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:15531
[junit4:junit4] 2> 15604 T1533 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cda94c454000e with negotiated timeout 20000 for client /140.211.11.196:15531
[junit4:junit4] 2> 15604 T1631 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26209, sessionid = 0x13cda94c454000e, negotiated timeout = 20000
[junit4:junit4] 2> 15604 T1632 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1375d753 name:ZooKeeperConnection Watcher:127.0.0.1:26209/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 15605 T1529 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 15606 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c454000e type:create cxid:0x1 zxid:0xc0 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 15608 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c454000e type:create cxid:0x2 zxid:0xc1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 15616 T1529 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 15618 T1529 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:15529_cvk%2Fhy
[junit4:junit4] 2> 15619 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c454000e type:delete cxid:0x9 zxid:0xc2 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:15529_cvk%2Fhy Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:15529_cvk%2Fhy
[junit4:junit4] 2> 15620 T1529 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:15529_cvk%2Fhy
[junit4:junit4] 2> 15624 T1585 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> 15624 T1615 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> 15624 T1570 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 15624 T1557 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> 15624 T1551 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> 15625 T1570 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> 15624 T1600 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 15624 T1632 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 15626 T1600 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> 15627 T1585 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 15628 T1615 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 15629 T1557 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 15629 T1551 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 15636 T1633 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1360876863498/collection1
[junit4:junit4] 2> 15636 T1633 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 15637 T1633 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 15637 T1633 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 15639 T1633 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1360876863498/collection1/'
[junit4:junit4] 2> 15640 T1633 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1360876863498/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 15640 T1633 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1360876863498/collection1/lib/README' to classloader
[junit4:junit4] 2> 15702 T1633 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 15778 T1633 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 15780 T1633 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 15786 T1633 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 15853 T1552 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 15854 T1552 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[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:27189_cvk%2Fhy",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:27189/cvk/hy"}
[junit4:junit4] 2> 15868 T1632 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> 15868 T1585 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> 15868 T1600 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> 15868 T1557 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> 15868 T1551 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> 15868 T1570 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> 15868 T1615 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> 16437 T1633 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 16448 T1633 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 16453 T1633 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 16467 T1633 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 16473 T1633 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 16478 T1633 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 16479 T1633 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 16480 T1633 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1360876863498/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty5/
[junit4:junit4] 2> 16481 T1633 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@25a75631
[junit4:junit4] 2> 16481 T1633 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 16482 T1633 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty5 forceNew:false
[junit4:junit4] 2> 16483 T1633 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty5
[junit4:junit4] 2> 16483 T1633 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty5/index/
[junit4:junit4] 2> 16484 T1633 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty5/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 16486 T1633 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty5/index forceNew:false
[junit4:junit4] 2> 16516 T1633 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty5/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@75945805),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 16517 T1633 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 16518 T1633 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty5/index
[junit4:junit4] 2> 16518 T1633 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 16520 T1633 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 16520 T1633 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 16521 T1633 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 16521 T1633 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 16522 T1633 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 16522 T1633 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 16522 T1633 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 16523 T1633 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 16524 T1633 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 16524 T1633 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 16525 T1633 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 16525 T1633 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 16526 T1633 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 16526 T1633 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 16526 T1633 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 16527 T1633 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 16527 T1633 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 16528 T1633 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 16529 T1633 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 16529 T1633 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 16530 T1633 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 16530 T1633 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 16531 T1633 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 16531 T1633 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 16532 T1633 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 16532 T1633 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 16546 T1633 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 16551 T1633 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 16553 T1633 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 16556 T1633 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty5
[junit4:junit4] 2> 16558 T1633 oass.SolrIndexSearcher.<init> Opening Searcher@63047bd8 main
[junit4:junit4] 2> 16559 T1633 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 16559 T1633 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 16560 T1633 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 16567 T1633 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 16627 T1634 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@63047bd8 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 16632 T1633 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 16632 T1633 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 17373 T1552 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 17374 T1552 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[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:15529_cvk%2Fhy",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:15529/cvk/hy"}
[junit4:junit4] 2> 17374 T1552 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 17375 T1552 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 17387 T1551 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> 17387 T1600 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> 17387 T1557 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> 17387 T1585 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> 17387 T1570 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> 17387 T1615 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> 17387 T1632 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> 17635 T1633 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 17635 T1633 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:15529/cvk/hy collection:collection1 shard:shard2
[junit4:junit4] 2> 17639 T1633 oasc.ZkController.register We are http://127.0.0.1:15529/cvk/hy/collection1/ and leader is http://127.0.0.1:64869/cvk/hy/collection1/
[junit4:junit4] 2> 17639 T1633 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:15529/cvk/hy
[junit4:junit4] 2> 17639 T1633 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 17639 T1633 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C91 name=collection1 org.apache.solr.core.SolrCore@78f8226e url=http://127.0.0.1:15529/cvk/hy/collection1 node=127.0.0.1:15529_cvk%2Fhy C91_STATE=coll:collection1 core:collection1 props:{shard=null, roles=null, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:15529_cvk%2Fhy, base_url=http://127.0.0.1:15529/cvk/hy}
[junit4:junit4] 2> 17641 T1635 C91 P15529 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 17641 T1633 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 17641 T1635 C91 P15529 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 17642 T1635 C91 P15529 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 17642 T1635 C91 P15529 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 17642 T1529 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0
[junit4:junit4] 2> 17643 T1529 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 17643 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 17645 T1635 C91 P15529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 17825 T1529 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 17828 T1529 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:15540
[junit4:junit4] 2> 17829 T1529 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 17829 T1529 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 17830 T1529 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1360876865860
[junit4:junit4] 2> 17830 T1529 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1360876865860/solr.xml
[junit4:junit4] 2> 17831 T1529 oasc.CoreContainer.<init> New CoreContainer 77551727
[junit4:junit4] 2> 17831 T1529 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1360876865860/'
[junit4:junit4] 2> 17832 T1529 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1360876865860/'
[junit4:junit4] 2> 17891 T1529 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 17892 T1529 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 17893 T1529 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 17893 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 17894 T1529 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 17894 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 17894 T1529 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 17895 T1529 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 17895 T1529 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 17896 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 17915 T1529 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 17935 T1529 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:26209/solr
[junit4:junit4] 2> 17935 T1529 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 17936 T1529 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26209 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@51562a6e
[junit4:junit4] 2> 17937 T1529 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 17937 T1645 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26209. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 17938 T1645 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26209, initiating session
[junit4:junit4] 2> 17939 T1531 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:15541
[junit4:junit4] 2> 17939 T1531 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:15541
[junit4:junit4] 2> 17941 T1533 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cda94c454000f with negotiated timeout 20000 for client /140.211.11.196:15541
[junit4:junit4] 2> 17941 T1645 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26209, sessionid = 0x13cda94c454000f, negotiated timeout = 20000
[junit4:junit4] 2> 17941 T1646 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51562a6e name:ZooKeeperConnection Watcher:127.0.0.1:26209 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 17941 T1529 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 17944 T1534 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cda94c454000f
[junit4:junit4] 2> 17945 T1646 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 17945 T1531 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:15541 which had sessionid 0x13cda94c454000f
[junit4:junit4] 2> 17945 T1529 oaz.ZooKeeper.close Session: 0x13cda94c454000f closed
[junit4:junit4] 2> 17946 T1529 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 17956 T1529 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26209/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@751df2ca
[junit4:junit4] 2> 17957 T1529 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 17957 T1647 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26209. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 17958 T1647 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26209, initiating session
[junit4:junit4] 2> 17958 T1531 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:15542
[junit4:junit4] 2> 17958 T1531 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:15542
[junit4:junit4] 2> 17959 T1533 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cda94c4540010 with negotiated timeout 20000 for client /140.211.11.196:15542
[junit4:junit4] 2> 17959 T1647 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26209, sessionid = 0x13cda94c4540010, negotiated timeout = 20000
[junit4:junit4] 2> 17960 T1648 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@751df2ca name:ZooKeeperConnection Watcher:127.0.0.1:26209/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 17960 T1529 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 17961 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540010 type:create cxid:0x1 zxid:0xd3 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 17963 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540010 type:create cxid:0x2 zxid:0xd4 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 17971 T1529 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 17973 T1529 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:15540_cvk%2Fhy
[junit4:junit4] 2> 17974 T1534 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cda94c4540010 type:delete cxid:0x9 zxid:0xd5 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:15540_cvk%2Fhy Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:15540_cvk%2Fhy
[junit4:junit4] 2> 17975 T1529 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:15540_cvk%2Fhy
[junit4:junit4] 2> 17978 T1585 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> 17978 T1551 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> 17978 T1615 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> 17978 T1570 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 17978 T1600 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 17979 T1570 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> 17978 T1648 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 17978 T1557 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> 17979 T1600 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> 17978 T1632 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 17980 T1551 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 17980 T1632 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> 17986 T1615 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 17987 T1557 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 17987 T1585 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 17992 T1649 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1360876865860/collection1
[junit4:junit4] 2> 17993 T1649 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 17993 T1649 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 17993 T1649 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 17995 T1649 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1360876865860/collection1/'
[junit4:junit4] 2> 17996 T1649 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1360876865860/collection1/lib/README' to classloader
[junit4:junit4] 2> 17997 T1649 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1360876865860/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 18053 T1649 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 18124 T1649 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 18125 T1649 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 18131 T1649 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> C90_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:27189_cvk%2Fhy, base_url=http://127.0.0.1:27189/cvk/hy}
[junit4:junit4] 2> 18301 T1619 C90 P27189 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:21009/cvk/hy/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 18301 T1619 C90 P27189 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:27189/cvk/hy START replicas=[http://127.0.0.1:21009/cvk/hy/collection1/] nUpdates=100
[junit4:junit4] 2> 18302 T1619 C90 P27189 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 18303 T1619 C90 P27189 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 18303 T1619 C90 P27189 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 18303 T1619 C90 P27189 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 18303 T1619 C90 P27189 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 18303 T1619 C90 P27189 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:21009/cvk/hy/collection1/. core=collection1
[junit4:junit4] 2> 18304 T1619 C90 P27189 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C92 name=collection1 org.apache.solr.core.SolrCore@1ec835ba url=http://127.0.0.1:21009/cvk/hy/collection1 node=127.0.0.1:21009_cvk%2Fhy C92_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:21009_cvk%2Fhy, base_url=http://127.0.0.1:21009/cvk/hy, leader=true}
[junit4:junit4] 2> 18313 T1561 C92 P21009 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 18316 T1562 C92 P21009 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4] 2> 18317 T1562 C92 P21009 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty1
[junit4:junit4] 2> 18321 T1562 C92 P21009 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1dfdcae5),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 18322 T1562 C92 P21009 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 18339 T1562 C92 P21009 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1dfdcae5),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1dfdcae5),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 18339 T1562 C92 P21009 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 18341 T1562 C92 P21009 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360876848207/jetty1
[junit4:junit4] 2> 18341 T1562 C92 P21009 oass.SolrIndexSearcher.<init> Opening Searcher@29d9047 realtime
[junit4:junit4] 2> 18342 T1562 C92 P21009 oasu.DirectUpdateHandler2.commit end
[...truncated too long message...]
:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:280)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235)
[junit4:junit4] 2> at org.eclipse.jetty.server.BlockingHttpConnection.handle(BlockingHttpConnection.java:72)
[junit4:junit4] 2> at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.run(SocketConnector.java:264)
[junit4:junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4:junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 56) Thread[id=1637, name=qtp1193592824-1637 Acceptor0 SocketConnector@127.0.0.1:15540, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4] 2> at java.net.PlainSocketImpl.socketAccept(Native Method)
[junit4:junit4] 2> at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398)
[junit4:junit4] 2> at java.net.ServerSocket.implAccept(ServerSocket.java:522)
[junit4:junit4] 2> at java.net.ServerSocket.accept(ServerSocket.java:490)
[junit4:junit4] 2> at org.eclipse.jetty.server.bio.SocketConnector.accept(SocketConnector.java:117)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:938)
[junit4:junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4:junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 57) Thread[id=1952, name=HashSessionScavenger-47, state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4] 2> at java.lang.Object.wait(Native Method)
[junit4:junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:552)
[junit4:junit4] 2> at java.util.TimerThread.run(Timer.java:505)
[junit4:junit4] 2> 58) Thread[id=1559, name=qtp565551170-1559 Acceptor0 SocketConnector@127.0.0.1:21009, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4] 2> at java.net.PlainSocketImpl.socketAccept(Native Method)
[junit4:junit4] 2> at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398)
[junit4:junit4] 2> at java.net.ServerSocket.implAccept(ServerSocket.java:522)
[junit4:junit4] 2> at java.net.ServerSocket.accept(ServerSocket.java:490)
[junit4:junit4] 2> at org.eclipse.jetty.server.bio.SocketConnector.accept(SocketConnector.java:117)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:938)
[junit4:junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4:junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 59) Thread[id=1956, name=qtp1502215133-1956, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4] 2> at java.net.SocketInputStream.socketRead0(Native Method)
[junit4:junit4] 2> at java.net.SocketInputStream.read(SocketInputStream.java:150)
[junit4:junit4] 2> at java.net.SocketInputStream.read(SocketInputStream.java:121)
[junit4:junit4] 2> at org.eclipse.jetty.io.ByteArrayBuffer.readFrom(ByteArrayBuffer.java:375)
[junit4:junit4] 2> at org.eclipse.jetty.io.bio.StreamEndPoint.fill(StreamEndPoint.java:141)
[junit4:junit4] 2> at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.fill(SocketConnector.java:227)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.fill(HttpParser.java:1035)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:280)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235)
[junit4:junit4] 2> at org.eclipse.jetty.server.BlockingHttpConnection.handle(BlockingHttpConnection.java:72)
[junit4:junit4] 2> at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.run(SocketConnector.java:264)
[junit4:junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4:junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 60) Thread[id=1997, name=qtp565551170-1997, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4] 2> at java.net.SocketInputStream.socketRead0(Native Method)
[junit4:junit4] 2> at java.net.SocketInputStream.read(SocketInputStream.java:150)
[junit4:junit4] 2> at java.net.SocketInputStream.read(SocketInputStream.java:121)
[junit4:junit4] 2> at org.eclipse.jetty.io.ByteArrayBuffer.readFrom(ByteArrayBuffer.java:375)
[junit4:junit4] 2> at org.eclipse.jetty.io.bio.StreamEndPoint.fill(StreamEndPoint.java:141)
[junit4:junit4] 2> at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.fill(SocketConnector.java:227)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.fill(HttpParser.java:1035)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:280)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235)
[junit4:junit4] 2> at org.eclipse.jetty.server.BlockingHttpConnection.handle(BlockingHttpConnection.java:72)
[junit4:junit4] 2> at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.run(SocketConnector.java:264)
[junit4:junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4:junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {range_facet_l=PostingsFormat(name=MockSep), text=MockFixedIntBlock(blockSize=412), _version_=PostingsFormat(name=Direct), rnd_b=PostingsFormat(name=MockRandom), intDefault=PostingsFormat(name=Direct), timestamp=PostingsFormat(name=MockSep), id=PostingsFormat(name=MockRandom), a_t=PostingsFormat(name=MockSep), range_facet_sl=PostingsFormat(name=MockRandom), range_facet_si=PostingsFormat(name=MockSep), other_tl1=PostingsFormat(name=Direct), multiDefault=PostingsFormat(name=MockSep), a_si=PostingsFormat(name=Direct)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=sr_ME_#Latn, timezone=PST
[junit4:junit4] 2> NOTE: FreeBSD 9.0-RELEASE amd64/Oracle Corporation 1.7.0_09 (64-bit)/cpus=16,threads=101,free=206000912,total=536870912
[junit4:junit4] 2> NOTE: All tests run in this JVM: [UniqFieldsUpdateProcessorFactoryTest, TestConfig, SpatialFilterTest, LeaderElectionIntegrationTest, ShardRoutingTest, MoreLikeThisHandlerTest, SimplePostToolTest, TestFaceting, TestIBSimilarityFactory, SolrPluginUtilsTest, TestJoin, LoggingHandlerTest, NumericFieldsTest, HighlighterConfigTest, TestGroupingSearch, SyncSliceTest, TestStressRecovery, DistributedTermsComponentTest, TestPartialUpdateDeduplication, TestExtendedDismaxParser, PreAnalyzedFieldTest, WordBreakSolrSpellCheckerTest, TestJmxMonitoredMap, TestFastOutputStream, TermsComponentTest, TestDefaultSimilarityFactory, TestQuerySenderNoQuery, SampleTest, DefaultValueUpdateProcessorTest, ResourceLoaderTest, BasicDistributedZkTest, CoreContainerCoreInitFailuresTest, TestCoreContainer, ResponseLogComponentTest, ScriptEngineTest, AutoCommitTest, TestFastWriter, AlternateDirectoryTest, ChaosMonkeySafeLeaderTest]
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.seed=101AD7A038114CF6 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=sr_ME_#Latn -Dtests.timezone=PST -Dtests.file.encoding=US-ASCII
[junit4:junit4] ERROR 0.00s J0 | ChaosMonkeySafeLeaderTest (suite) <<<
[junit4:junit4] > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([101AD7A038114CF6]:0)
[junit4:junit4] Completed on J0 in 7224.38s, 1 test, 2 errors <<< FAILURES!
[...truncated 74 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/build.xml:381: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/build.xml:361: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build.xml:183: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/common-build.xml:447: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/lucene/common-build.xml:1202: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/lucene/common-build.xml:865: There were test failures: 250 suites, 1040 tests, 1 suite-level error, 1 error, 79 ignored (2 assumptions)
Total time: 159 minutes 54 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure