lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-4.x-Windows (32bit/jdk1.7.0_45) - Build # 3341 - Failure!
Date Sat, 02 Nov 2013 06:49:36 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/3341/
Java: 32bit/jdk1.7.0_45 -client -XX:+UseSerialGC

2 tests failed.
FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest

Error Message:
9 threads leaked from SUITE scope at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest:     1) Thread[id=2140, name=qtp2568862-2140, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)         at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)         at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)         at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)         at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)         at java.lang.Thread.run(Thread.java:744)    2) Thread[id=2141, name=qtp2568862-2141, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)         at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)         at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)         at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)         at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)         at java.lang.Thread.run(Thread.java:744)    3) Thread[id=2139, name=qtp2568862-2139, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)         at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)         at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)         at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)         at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)         at java.lang.Thread.run(Thread.java:744)    4) Thread[id=2142, name=qtp2568862-2142, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)         at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)         at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)         at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)         at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)         at java.lang.Thread.run(Thread.java:744)    5) Thread[id=2136, name=HashSessionScavenger-71, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]         at java.lang.Object.wait(Native Method)         at java.util.TimerThread.mainLoop(Timer.java:552)         at java.util.TimerThread.run(Timer.java:505)    6) Thread[id=2143, name=qtp2568862-2143, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)         at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)         at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)         at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)         at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)         at java.lang.Thread.run(Thread.java:744)    7) Thread[id=2137, name=qtp2568862-2137 Selector0, state=RUNNABLE, group=TGRP-ChaosMonkeyNothingIsSafeTest]         at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)         at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:296)         at sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(WindowsSelectorImpl.java:278)         at sun.nio.ch.WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:159)         at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)         at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)         at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:569)         at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)         at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)         at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)         at java.lang.Thread.run(Thread.java:744)    8) Thread[id=2138, name=qtp2568862-2138 Acceptor0 SelectChannelConnector@127.0.0.1:64571, state=RUNNABLE, group=TGRP-ChaosMonkeyNothingIsSafeTest]         at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)         at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:241)         at org.eclipse.jetty.server.nio.SelectChannelConnector.accept(SelectChannelConnector.java:109)         at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:938)         at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)         at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)         at java.lang.Thread.run(Thread.java:744)    9) Thread[id=2144, name=qtp2568862-2144, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)         at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)         at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)         at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)         at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)         at java.lang.Thread.run(Thread.java:744)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 9 threads leaked from SUITE scope at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest: 
   1) Thread[id=2140, name=qtp2568862-2140, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
        at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
        at java.lang.Thread.run(Thread.java:744)
   2) Thread[id=2141, name=qtp2568862-2141, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
        at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
        at java.lang.Thread.run(Thread.java:744)
   3) Thread[id=2139, name=qtp2568862-2139, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
        at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
        at java.lang.Thread.run(Thread.java:744)
   4) Thread[id=2142, name=qtp2568862-2142, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
        at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
        at java.lang.Thread.run(Thread.java:744)
   5) Thread[id=2136, name=HashSessionScavenger-71, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]
        at java.lang.Object.wait(Native Method)
        at java.util.TimerThread.mainLoop(Timer.java:552)
        at java.util.TimerThread.run(Timer.java:505)
   6) Thread[id=2143, name=qtp2568862-2143, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
        at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
        at java.lang.Thread.run(Thread.java:744)
   7) Thread[id=2137, name=qtp2568862-2137 Selector0, state=RUNNABLE, group=TGRP-ChaosMonkeyNothingIsSafeTest]
        at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
        at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:296)
        at sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(WindowsSelectorImpl.java:278)
        at sun.nio.ch.WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:159)
        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
        at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:569)
        at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
        at java.lang.Thread.run(Thread.java:744)
   8) Thread[id=2138, name=qtp2568862-2138 Acceptor0 SelectChannelConnector@127.0.0.1:64571, state=RUNNABLE, group=TGRP-ChaosMonkeyNothingIsSafeTest]
        at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
        at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:241)
        at org.eclipse.jetty.server.nio.SelectChannelConnector.accept(SelectChannelConnector.java:109)
        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:938)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
        at java.lang.Thread.run(Thread.java:744)
   9) Thread[id=2144, name=qtp2568862-2144, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
        at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
        at java.lang.Thread.run(Thread.java:744)
	at __randomizedtesting.SeedInfo.seed([8545BBDEA8552F21]:0)


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

Error Message:
There are still zombie threads that couldn't be terminated:    1) Thread[id=2136, name=HashSessionScavenger-71, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]         at java.lang.Object.wait(Native Method)         at java.util.TimerThread.mainLoop(Timer.java:552)         at java.util.TimerThread.run(Timer.java:505)    2) Thread[id=2137, name=qtp2568862-2137 Selector0, state=RUNNABLE, group=TGRP-ChaosMonkeyNothingIsSafeTest]         at java.lang.Object.notifyAll(Native Method)         at sun.nio.ch.WindowsSelectorImpl$StartLock.startThreads(WindowsSelectorImpl.java:189)         at sun.nio.ch.WindowsSelectorImpl$StartLock.access$300(WindowsSelectorImpl.java:181)         at sun.nio.ch.WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:153)         at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)         at sun.nio.ch.SelectorImpl.selectNow(SelectorImpl.java:106)         at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:536)         at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)         at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)         at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)         at java.lang.Thread.run(Thread.java:744)    3) Thread[id=2138, name=qtp2568862-2138 Acceptor0 SelectChannelConnector@127.0.0.1:64571, state=RUNNABLE, group=TGRP-ChaosMonkeyNothingIsSafeTest]         at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:934)         at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)         at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)         at java.lang.Thread.run(Thread.java:744)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   1) Thread[id=2136, name=HashSessionScavenger-71, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]
        at java.lang.Object.wait(Native Method)
        at java.util.TimerThread.mainLoop(Timer.java:552)
        at java.util.TimerThread.run(Timer.java:505)
   2) Thread[id=2137, name=qtp2568862-2137 Selector0, state=RUNNABLE, group=TGRP-ChaosMonkeyNothingIsSafeTest]
        at java.lang.Object.notifyAll(Native Method)
        at sun.nio.ch.WindowsSelectorImpl$StartLock.startThreads(WindowsSelectorImpl.java:189)
        at sun.nio.ch.WindowsSelectorImpl$StartLock.access$300(WindowsSelectorImpl.java:181)
        at sun.nio.ch.WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:153)
        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
        at sun.nio.ch.SelectorImpl.selectNow(SelectorImpl.java:106)
        at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:536)
        at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
        at java.lang.Thread.run(Thread.java:744)
   3) Thread[id=2138, name=qtp2568862-2138 Acceptor0 SelectChannelConnector@127.0.0.1:64571, state=RUNNABLE, group=TGRP-ChaosMonkeyNothingIsSafeTest]
        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:934)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
        at java.lang.Thread.run(Thread.java:744)
	at __randomizedtesting.SeedInfo.seed([8545BBDEA8552F21]:0)




Build Log:
[...truncated 10088 lines...]
   [junit4] Suite: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest
   [junit4]   2> 790034 T1923 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /nklq/d
   [junit4]   2> 790042 T1923 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-ChaosMonkeyNothingIsSafeTest-1383374475280
   [junit4]   2> 790047 T1923 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 790048 T1924 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 790145 T1923 oasc.ZkTestServer.run start zk server on port:64552
   [junit4]   2> 790147 T1923 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 790153 T1930 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a18218 name:ZooKeeperConnection Watcher:127.0.0.1:64552 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 790154 T1923 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 790154 T1923 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 790162 T1923 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 790165 T1932 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12c972e name:ZooKeeperConnection Watcher:127.0.0.1:64552/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 790166 T1923 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 790166 T1923 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 790173 T1923 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 790177 T1923 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 790182 T1923 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 790189 T1923 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 790190 T1923 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 790198 T1923 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 790199 T1923 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 790205 T1923 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 790206 T1923 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 790210 T1923 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 790211 T1923 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 790218 T1923 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 790219 T1923 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 790223 T1923 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 790224 T1923 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 790231 T1923 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 790232 T1923 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 790237 T1923 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 790238 T1923 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 790243 T1923 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 790243 T1923 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 790249 T1923 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 790250 T1923 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 790783 T1923 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 790795 T1923 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:64559
   [junit4]   2> 790796 T1923 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 790797 T1923 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 790797 T1923 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383374475491
   [junit4]   2> 790798 T1923 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383374475491\'
   [junit4]   2> 790853 T1923 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383374475491\solr.xml
   [junit4]   2> 791005 T1923 oasc.CoreContainer.<init> New CoreContainer 5643302
   [junit4]   2> 791006 T1923 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383374475491\]
   [junit4]   2> 791010 T1923 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
   [junit4]   2> 791010 T1923 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 791010 T1923 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 791010 T1923 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 791011 T1923 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 791011 T1923 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 791012 T1923 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 791012 T1923 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 791012 T1923 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 791017 T1923 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 791018 T1923 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 791018 T1923 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:64552/solr
   [junit4]   2> 791019 T1923 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 791021 T1923 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 791031 T1943 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d0bbb8 name:ZooKeeperConnection Watcher:127.0.0.1:64552 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 791031 T1923 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 791040 T1923 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 791043 T1945 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@126ab55 name:ZooKeeperConnection Watcher:127.0.0.1:64552/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 791043 T1923 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 791046 T1923 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 791055 T1923 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 791061 T1923 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 791065 T1923 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64559_nklq%2Fd
   [junit4]   2> 791067 T1923 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:64559_nklq%2Fd
   [junit4]   2> 791073 T1923 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 791085 T1923 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 791089 T1923 oasc.Overseer.start Overseer (id=90660829612933123-127.0.0.1:64559_nklq%2Fd-n_0000000000) starting
   [junit4]   2> 791097 T1923 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 791105 T1947 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 791108 T1923 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 791115 T1923 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 791118 T1923 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 791125 T1946 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 791134 T1948 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 791135 T1948 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 791137 T1948 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 792574 T1946 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 792575 T1946 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:64559/nklq/d",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:64559_nklq%2Fd",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 792576 T1946 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 792576 T1946 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 792587 T1945 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 793059 T1948 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 793059 T1948 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383374475491\collection1
   [junit4]   2> 793059 T1948 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 793062 T1948 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 793062 T1948 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 793064 T1948 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383374475491\collection1\'
   [junit4]   2> 793068 T1948 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383374475491/collection1/lib/classes/' to classloader
   [junit4]   2> 793068 T1948 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383374475491/collection1/lib/README' to classloader
   [junit4]   2> 793158 T1948 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 793252 T1948 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 793256 T1948 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 793272 T1948 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 794312 T1948 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 794313 T1948 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 794314 T1948 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 794324 T1948 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 794329 T1948 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 794354 T1948 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 794360 T1948 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 794366 T1948 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 794369 T1948 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 794369 T1948 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 794369 T1948 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 794371 T1948 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 794371 T1948 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 794371 T1948 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 794372 T1948 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383374475491\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278/control/data\
   [junit4]   2> 794372 T1948 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@9c252c
   [junit4]   2> 794372 T1948 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278\control\data
   [junit4]   2> 794375 T1948 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278/control/data\index/
   [junit4]   2> 794375 T1948 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278\control\data\index' doesn't exist. Creating new index...
   [junit4]   2> 794376 T1948 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278\control\data\index
   [junit4]   2> 794376 T1948 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=24, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.42488224789307183]
   [junit4]   2> 794384 T1948 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278\control\data\index,segFN=segments_1,generation=1}
   [junit4]   2> 794384 T1948 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 794387 T1948 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 794387 T1948 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 794388 T1948 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 794388 T1948 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 794388 T1948 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 794388 T1948 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 794390 T1948 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 794390 T1948 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 794390 T1948 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 794390 T1948 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 794390 T1948 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 794390 T1948 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 794390 T1948 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 794392 T1948 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 794392 T1948 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 794400 T1948 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 794407 T1948 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 794407 T1948 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 794408 T1948 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=37, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 794409 T1948 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278\control\data\index,segFN=segments_1,generation=1}
   [junit4]   2> 794409 T1948 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 794409 T1948 oass.SolrIndexSearcher.<init> Opening Searcher@169c475 main
   [junit4]   2> 794417 T1949 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@169c475 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 794418 T1948 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 794418 T1948 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:64559/nklq/d collection:control_collection shard:shard1
   [junit4]   2> 794420 T1948 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 794436 T1948 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 794442 T1948 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 794442 T1948 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 794442 T1948 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:64559/nklq/d/collection1/
   [junit4]   2> 794442 T1948 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 794442 T1948 oasc.SyncStrategy.syncToMe http://127.0.0.1:64559/nklq/d/collection1/ has no replicas
   [junit4]   2> 794442 T1948 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:64559/nklq/d/collection1/ shard1
   [junit4]   2> 794442 T1948 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 795480 T1946 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 795495 T1945 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 795529 T1948 oasc.ZkController.register We are http://127.0.0.1:64559/nklq/d/collection1/ and leader is http://127.0.0.1:64559/nklq/d/collection1/
   [junit4]   2> 795529 T1948 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:64559/nklq/d
   [junit4]   2> 795529 T1948 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 795529 T1948 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 795529 T1948 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 795534 T1948 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 795536 T1923 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 795537 T1923 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 795541 T1923 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 795544 T1952 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8c88c8 name:ZooKeeperConnection Watcher:127.0.0.1:64552/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 795545 T1923 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 795547 T1923 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 795552 T1923 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 796036 T1923 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 796042 T1923 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:64571
   [junit4]   2> 796043 T1923 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 796043 T1923 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 796043 T1923 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383374480787
   [junit4]   2> 796044 T1923 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383374480787\'
   [junit4]   2> 796076 T1923 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383374480787\solr.xml
   [junit4]   2> 796168 T1923 oasc.CoreContainer.<init> New CoreContainer 32432440
   [junit4]   2> 796168 T1923 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383374480787\]
   [junit4]   2> 796170 T1923 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
   [junit4]   2> 796171 T1923 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 796171 T1923 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 796172 T1923 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 796172 T1923 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 796173 T1923 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 796173 T1923 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 796173 T1923 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 796174 T1923 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 796178 T1923 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 796178 T1923 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 796178 T1923 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:64552/solr
   [junit4]   2> 796179 T1923 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 796181 T1923 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 796191 T1963 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@dbf68e name:ZooKeeperConnection Watcher:127.0.0.1:64552 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 796193 T1923 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 796196 T1925 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x142178b501f0005, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 796200 T1923 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 796213 T1965 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a090b0 name:ZooKeeperConnection Watcher:127.0.0.1:64552/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 796213 T1923 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 796222 T1923 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 796946 T1946 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 796948 T1946 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:64559/nklq/d",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:64559_nklq%2Fd",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 796956 T1952 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 796956 T1965 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 796958 T1945 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 797189 T1923 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64571_nklq%2Fd
   [junit4]   2> 797195 T1923 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:64571_nklq%2Fd
   [junit4]   2> 797203 T1965 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 797204 T1945 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 797204 T1952 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 797223 T1966 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 797223 T1966 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 797224 T1966 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 798407 T1946 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 798408 T1946 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:64571/nklq/d",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:64571_nklq%2Fd",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 798408 T1946 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 798410 T1946 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 798420 T1952 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 798420 T1965 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 798420 T1945 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 799146 T1966 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 799146 T1966 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383374480787\collection1
   [junit4]   2> 799146 T1966 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 799149 T1966 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 799149 T1966 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 799151 T1966 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383374480787\collection1\'
   [junit4]   2> 799154 T1966 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383374480787/collection1/lib/classes/' to classloader
   [junit4]   2> 799154 T1966 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383374480787/collection1/lib/README' to classloader
   [junit4]   2> 799270 T1966 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 799391 T1966 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 799394 T1966 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 799415 T1966 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 800235 T1966 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 800236 T1966 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 800236 T1966 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 800248 T1966 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 800252 T1966 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 800277 T1966 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 800284 T1966 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 800293 T1966 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 800295 T1966 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 800295 T1966 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 800295 T1966 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 800299 T1966 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 800299 T1966 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 800299 T1966 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 800299 T1966 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383374480787\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278/jetty1\
   [junit4]   2> 800299 T1966 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@9c252c
   [junit4]   2> 800299 T1966 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278\jetty1
   [junit4]   2> 800301 T1966 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278/jetty1\index/
   [junit4]   2> 800303 T1966 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278\jetty1\index' doesn't exist. Creating new index...
   [junit4]   2> 800303 T1966 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278\jetty1\index
   [junit4]   2> 800304 T1966 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=24, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.42488224789307183]
   [junit4]   2> 800311 T1966 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278\jetty1\index,segFN=segments_1,generation=1}
   [junit4]   2> 800311 T1966 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 800316 T1966 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 800317 T1966 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 800317 T1966 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 800318 T1966 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 800319 T1966 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 800319 T1966 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 800320 T1966 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 800320 T1966 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 800320 T1966 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 800321 T1966 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 800323 T1966 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 800323 T1966 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 800323 T1966 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 800325 T1966 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 800326 T1966 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 800338 T1966 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 800347 T1966 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 800348 T1966 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 800348 T1966 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=37, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 800351 T1966 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278\jetty1\index,segFN=segments_1,generation=1}
   [junit4]   2> 800351 T1966 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 800352 T1966 oass.SolrIndexSearcher.<init> Opening Searcher@192718c main
   [junit4]   2> 800360 T1967 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@192718c main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 800361 T1966 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 800361 T1966 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:64571/nklq/d collection:collection1 shard:shard1
   [junit4]   2> 800364 T1966 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 800375 T1966 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 800380 T1966 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 800380 T1966 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 800380 T1966 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:64571/nklq/d/collection1/
   [junit4]   2> 800380 T1966 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 800380 T1966 oasc.SyncStrategy.syncToMe http://127.0.0.1:64571/nklq/d/collection1/ has no replicas
   [junit4]   2> 800380 T1966 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:64571/nklq/d/collection1/ shard1
   [junit4]   2> 800380 T1966 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 801158 T1946 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 801172 T1945 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 801173 T1965 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 801172 T1952 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 801188 T1966 oasc.ZkController.register We are http://127.0.0.1:64571/nklq/d/collection1/ and leader is http://127.0.0.1:64571/nklq/d/collection1/
   [junit4]   2> 801188 T1966 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:64571/nklq/d
   [junit4]   2> 801188 T1966 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 801188 T1966 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 801188 T1966 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 801191 T1966 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 801193 T1923 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 801193 T1923 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 801663 T1923 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 801669 T1923 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:64580
   [junit4]   2> 801671 T1923 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 801671 T1923 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 801671 T1923 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383374486430
   [junit4]   2> 801671 T1923 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383374486430\'
   [junit4]   2> 801700 T1923 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383374486430\solr.xml
   [junit4]   2> 801781 T1923 oasc.CoreContainer.<init> New CoreContainer 22848797
   [junit4]   2> 801782 T1923 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383374486430\]
   [junit4]   2> 801784 T1923 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
   [junit4]   2> 801784 T1923 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 801785 T1923 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 801785 T1923 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 801785 T1923 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 801785 T1923 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 801785 T1923 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 801786 T1923 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 801786 T1923 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 801790 T1923 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 801790 T1923 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 801791 T1923 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:64552/solr
   [junit4]   2> 801791 T1923 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 801793 T1923 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 801805 T1979 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8ffabb name:ZooKeeperConnection Watcher:127.0.0.1:64552 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 801806 T1923 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 801810 T1925 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x142178b501f0007, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 801814 T1923 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 801818 T1981 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8d238a name:ZooKeeperConnection Watcher:127.0.0.1:64552/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 801819 T1923 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 801826 T1923 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 802479 T1946 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 802481 T1946 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:64571/nklq/d",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:64571_nklq%2Fd",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 802489 T1952 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 802489 T1945 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 802490 T1965 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 802491 T1981 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 802696 T1923 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64580_nklq%2Fd
   [junit4]   2> 802700 T1923 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:64580_nklq%2Fd
   [junit4]   2> 802705 T1952 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 802706 T1945 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 802706 T1965 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 802706 T1981 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 802719 T1982 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 802719 T1982 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 802721 T1982 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 803796 T1946 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 803797 T1946 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:64580/nklq/d",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:64580_nklq%2Fd",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 803797 T1946 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 803797 T1946 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 803809 T1981 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 803809 T1952 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 803810 T1965 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 803809 T1945 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 804450 T1982 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 804450 T1982 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383374486430\collection1
   [junit4]   2> 804450 T1982 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 804452 T1982 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 804452 T1982 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 804455 T1982 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383374486430\collection1\'
   [junit4]   2> 804456 T1982 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383374486430/collection1/lib/classes/' to classloader
   [junit4]   2> 804458 T1982 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383374486430/collection1/lib/README' to classloader
   [junit4]   2> 804542 T1982 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 804610 T1982 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 804612 T1982 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 804621 T1982 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 805461 T1982 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 805461 T1982 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 805462 T1982 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 805472 T1982 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 805476 T1982 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 805513 T1982 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 805520 T1982 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 805528 T1982 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 805532 T1982 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 805532 T1982 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 805532 T1982 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 805535 T1982 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 805535 T1982 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 805535 T1982 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 805536 T1982 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383374486430\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278/jetty2\
   [junit4]   2> 805536 T1982 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@9c252c
   [junit4]   2> 805537 T1982 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278\jetty2
   [junit4]   2> 805539 T1982 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278/jetty2\index/
   [junit4]   2> 805539 T1982 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278\jetty2\index' doesn't exist. Creating new index...
   [junit4]   2> 805539 T1982 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278\jetty2\index
   [junit4]   2> 805541 T1982 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=24, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.42488224789307183]
   [junit4]   2> 805548 T1982 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278\jetty2\index,segFN=segments_1,generation=1}
   [junit4]   2> 805548 T1982 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 805553 T1982 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 805553 T1982 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 805553 T1982 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 805554 T1982 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 805555 T1982 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 805555 T1982 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 805556 T1982 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 805557 T1982 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 805557 T1982 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 805558 T1982 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 805559 T1982 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 805559 T1982 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 805559 T1982 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 805562 T1982 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 805562 T1982 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 805574 T1982 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 805580 T1982 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 805580 T1982 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 805581 T1982 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=37, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 805582 T1982 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383374475278\jetty2\index,segFN=segments_1,generation=1}
   [junit4]   2> 805582 T1982 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 805582 T1982 oass.SolrIndexSearcher.<init> Opening Searcher@d57c3f main
   [junit4]   2> 805591 T1983 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@d57c3f main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 805593 T1982 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 805593 T1982 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:64580/nklq/d collection:collection1 shard:shard2
   [junit4]   2> 805597 T1982 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 805609 T1982 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 805613 T1982 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 805613 T1982 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 805613 T1982 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:64580/nklq/d/collection1/
   [junit4]   2> 805613 T1982 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 805613 T1982 oasc.SyncStrategy.syncToMe http://127.0.0.1:64580/nklq/d/collection1/ has no replicas
   [junit4]   2> 805613 T1982 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:64580/nklq/d/collection1/ shard2
   [junit4]   2> 805613 T1982 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 806415 T1946 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 806431 T1981 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 806432 T1952 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 806432 T1965 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 806432 T1945 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 806459 T1982 oasc.ZkController.register We are http://127.0.0.1:64580/nklq/d/collection1/ and leader is http://127.0.0.1:64580/nklq/d/collection1/
   [junit4]   2> 806459 T1982 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:64580/nklq/d
   [junit4]   2> 806459 T1982 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 806459 T1982 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 806459 T1982 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 806464 T1982 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 806466 T1923 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 806467 T1923 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 806886 T1923 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 806890 T1923 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:64589
   [junit4]   2> 806892 T1923 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 806892 T1923 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 806893 T1923 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383374491703
   [junit4]   2> 806893 T1923 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383374491703\'
   [junit4]   2> 806919 T1923 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383374491703\solr.xml
   [junit4]   2> 807013 T1923 oasc.CoreContainer.<init> New CoreContainer 31787092
   [junit4]   2> 807013 T1923 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383374491703\]
   [junit4]   2> 807016 T1923 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
   [junit4]   2> 807016 T1923 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 807016 T1923 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 807016 T1923 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 807016 T1923 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 807016 T1923 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 807016 T1923 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 807016 T1923 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 807016 T1923 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 807019 T1923 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 807022 T1923 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 807022 T1923 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:64552/solr
   [junit4]   2> 807022 T1923 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 807023 T1923 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 807027 T1995 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13cbada name:ZooKeeperConnection Watcher:127.0.0.1:64552 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 807027 T1923 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 807033 T1923 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 807036 T1997 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e70f9f name:ZooKeeperConnection Watcher:127.0.0.1:64552/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 807036 T1923 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 807043 T1923 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 807739 T1946 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 807741 T1946 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:64580/nklq/d",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:64580_nklq%2Fd",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 807749 T1981 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 807749 T1997 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 807749 T1952 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... 

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

un(Thread.java:744)
   [junit4]    >    3) Thread[id=2139, name=qtp2568862-2139, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
   [junit4]    >         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
   [junit4]    >         at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
   [junit4]    >         at java.lang.Thread.run(Thread.java:744)
   [junit4]    >    4) Thread[id=2142, name=qtp2568862-2142, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
   [junit4]    >         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
   [junit4]    >         at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
   [junit4]    >         at java.lang.Thread.run(Thread.java:744)
   [junit4]    >    5) Thread[id=2136, name=HashSessionScavenger-71, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]
   [junit4]    >         at java.lang.Object.wait(Native Method)
   [junit4]    >         at java.util.TimerThread.mainLoop(Timer.java:552)
   [junit4]    >         at java.util.TimerThread.run(Timer.java:505)
   [junit4]    >    6) Thread[id=2143, name=qtp2568862-2143, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
   [junit4]    >         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
   [junit4]    >         at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
   [junit4]    >         at java.lang.Thread.run(Thread.java:744)
   [junit4]    >    7) Thread[id=2137, name=qtp2568862-2137 Selector0, state=RUNNABLE, group=TGRP-ChaosMonkeyNothingIsSafeTest]
   [junit4]    >         at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
   [junit4]    >         at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:296)
   [junit4]    >         at sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(WindowsSelectorImpl.java:278)
   [junit4]    >         at sun.nio.ch.WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:159)
   [junit4]    >         at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
   [junit4]    >         at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
   [junit4]    >         at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:569)
   [junit4]    >         at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]    >         at java.lang.Thread.run(Thread.java:744)
   [junit4]    >    8) Thread[id=2138, name=qtp2568862-2138 Acceptor0 SelectChannelConnector@127.0.0.1:64571, state=RUNNABLE, group=TGRP-ChaosMonkeyNothingIsSafeTest]
   [junit4]    >         at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
   [junit4]    >         at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:241)
   [junit4]    >         at org.eclipse.jetty.server.nio.SelectChannelConnector.accept(SelectChannelConnector.java:109)
   [junit4]    >         at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:938)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]    >         at java.lang.Thread.run(Thread.java:744)
   [junit4]    >    9) Thread[id=2144, name=qtp2568862-2144, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
   [junit4]    >         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
   [junit4]    >         at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
   [junit4]    >         at java.lang.Thread.run(Thread.java:744)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([8545BBDEA8552F21]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   [junit4]    >    1) Thread[id=2136, name=HashSessionScavenger-71, state=TIMED_WAITING, group=TGRP-ChaosMonkeyNothingIsSafeTest]
   [junit4]    >         at java.lang.Object.wait(Native Method)
   [junit4]    >         at java.util.TimerThread.mainLoop(Timer.java:552)
   [junit4]    >         at java.util.TimerThread.run(Timer.java:505)
   [junit4]    >    2) Thread[id=2137, name=qtp2568862-2137 Selector0, state=RUNNABLE, group=TGRP-ChaosMonkeyNothingIsSafeTest]
   [junit4]    >         at java.lang.Object.notifyAll(Native Method)
   [junit4]    >         at sun.nio.ch.WindowsSelectorImpl$StartLock.startThreads(WindowsSelectorImpl.java:189)
   [junit4]    >         at sun.nio.ch.WindowsSelectorImpl$StartLock.access$300(WindowsSelectorImpl.java:181)
   [junit4]    >         at sun.nio.ch.WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:153)
   [junit4]    >         at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
   [junit4]    >         at sun.nio.ch.SelectorImpl.selectNow(SelectorImpl.java:106)
   [junit4]    >         at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:536)
   [junit4]    >         at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]    >         at java.lang.Thread.run(Thread.java:744)
   [junit4]    >    3) Thread[id=2138, name=qtp2568862-2138 Acceptor0 SelectChannelConnector@127.0.0.1:64571, state=RUNNABLE, group=TGRP-ChaosMonkeyNothingIsSafeTest]
   [junit4]    >         at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:934)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]    >         at java.lang.Thread.run(Thread.java:744)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([8545BBDEA8552F21]:0)
   [junit4] Completed in 195.33s, 1 test, 2 errors <<< FAILURES!

[...truncated 822 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:428: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:408: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:483: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1263: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:906: There were test failures: 333 suites, 1469 tests, 2 suite-level errors, 1198 ignored (1 assumption)

Total time: 53 minutes 36 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_45 -client -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message