You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/02/20 01:53:28 UTC

[JENKINS] Lucene-Solr-trunk-Linux (64bit/ibm-j9-jdk7) - Build # 9531 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9531/
Java: 64bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}

4 tests failed.
REGRESSION:  org.apache.solr.analytics.expression.ExpressionTest.addTest

Error Message:
Caught exception in getStatResult, xPath = /response/lst[@name='stats']/lst[@name='ar']/double[@name='sum']  raw data: <?xml version="1.0" encoding="UTF-8"?> <response>  <lst name="responseHeader">   <int name="status">0</int>   <int name="QTime">4</int> </lst> <result name="response" numFound="100" start="0"> </result> <lst name="stats">   <lst name="stats_fields"/> </lst> <lst name="stats">   <lst name="ar">     <long name="count">100</long>     <null name="mcm"/>     <null name="mean"/>     <null name="median"/>     <null name="su"/>     <null name="sum"/>     <null name="unique"/>   </lst>   <lst name="dr">     <long name="count">100</long>     <double name="mc">0.2891</double>     <double name="mean">28.91</double>     <double name="su">80.30555555555556</double>     <double name="sum">2891.0</double>     <long name="unique">36</long>   </lst>   <lst name="rr">     <str name="max">str9</str>     <str name="min">str0</str>     <str name="rmax">9rts</str>     <str name="rmin">0rts</str>   </lst>   <lst name="cnr">     <double name="c10">10.0</double>     <double name="c8">8.0</double>   </lst>   <lst name="cdr">     <date name="cd1">1800-12-31T23:59:59Z</date>     <date name="cd2">1804-06-30T23:59:59Z</date>     <str name="cs1">1800-12-31T23:59:59Z</str>     <str name="cs2">1804-06-30T23:59:59Z</str>   </lst>   <lst name="dmr">     <str name="cma">+2MONTHS</str>     <str name="cme">+2YEARS</str>     <date name="dmma">1812-02-29T23:59:59Z</date>     <date name="dmme">1807-12-31T23:59:59Z</date>     <date name="max">1811-12-31T23:59:59Z</date>     <date name="median">1805-12-31T23:59:59Z</date>   </lst>   <lst name="pr">     <long name="count">100</long>     <double name="mc">1.2729436151389237E146</double>     <double name="mean">28.91</double>     <double name="su">3.9603293116911423E124</double>     <double name="sum">2891.0</double>     <long name="unique">36</long>   </lst>   <lst name="nr">     <double name="c">-100.0</double>     <long name="count">100</long>     <null name="s"/>     <null name="sum"/>   </lst>   <lst name="avr">     <double name="c">100.0</double>     <long name="count">100</long>     <double name="s">2891.0</double>     <double name="sum">2891.0</double>   </lst>   <lst name="mr">     <long name="count">100</long>     <double name="mcm">70829.5</double>     <double name="mean">28.91</double>     <double name="median">24.5</double>     <double name="su">104076.0</double>     <double name="sum">2891.0</double>     <long name="unique">36</long>   </lst>   <lst name="cr">     <str name="ccmax">this is the secondstr9</str>     <str name="ccmin">this is the firststr0</str>     <str name="csmax">this is the second</str>     <str name="csmin">this is the first</str>     <str name="max">str9</str>     <str name="min">str0</str>   </lst>   <lst name="csr">     <str name="cs1">this is the first</str>     <str name="cs2">this is the second</str>     <str name="cs3">this is the third</str>   </lst> </lst> </response> 

Stack Trace:
java.lang.AssertionError: Caught exception in getStatResult, xPath = /response/lst[@name='stats']/lst[@name='ar']/double[@name='sum'] 
raw data: <?xml version="1.0" encoding="UTF-8"?>
<response>

<lst name="responseHeader">
  <int name="status">0</int>
  <int name="QTime">4</int>
</lst>
<result name="response" numFound="100" start="0">
</result>
<lst name="stats">
  <lst name="stats_fields"/>
</lst>
<lst name="stats">
  <lst name="ar">
    <long name="count">100</long>
    <null name="mcm"/>
    <null name="mean"/>
    <null name="median"/>
    <null name="su"/>
    <null name="sum"/>
    <null name="unique"/>
  </lst>
  <lst name="dr">
    <long name="count">100</long>
    <double name="mc">0.2891</double>
    <double name="mean">28.91</double>
    <double name="su">80.30555555555556</double>
    <double name="sum">2891.0</double>
    <long name="unique">36</long>
  </lst>
  <lst name="rr">
    <str name="max">str9</str>
    <str name="min">str0</str>
    <str name="rmax">9rts</str>
    <str name="rmin">0rts</str>
  </lst>
  <lst name="cnr">
    <double name="c10">10.0</double>
    <double name="c8">8.0</double>
  </lst>
  <lst name="cdr">
    <date name="cd1">1800-12-31T23:59:59Z</date>
    <date name="cd2">1804-06-30T23:59:59Z</date>
    <str name="cs1">1800-12-31T23:59:59Z</str>
    <str name="cs2">1804-06-30T23:59:59Z</str>
  </lst>
  <lst name="dmr">
    <str name="cma">+2MONTHS</str>
    <str name="cme">+2YEARS</str>
    <date name="dmma">1812-02-29T23:59:59Z</date>
    <date name="dmme">1807-12-31T23:59:59Z</date>
    <date name="max">1811-12-31T23:59:59Z</date>
    <date name="median">1805-12-31T23:59:59Z</date>
  </lst>
  <lst name="pr">
    <long name="count">100</long>
    <double name="mc">1.2729436151389237E146</double>
    <double name="mean">28.91</double>
    <double name="su">3.9603293116911423E124</double>
    <double name="sum">2891.0</double>
    <long name="unique">36</long>
  </lst>
  <lst name="nr">
    <double name="c">-100.0</double>
    <long name="count">100</long>
    <null name="s"/>
    <null name="sum"/>
  </lst>
  <lst name="avr">
    <double name="c">100.0</double>
    <long name="count">100</long>
    <double name="s">2891.0</double>
    <double name="sum">2891.0</double>
  </lst>
  <lst name="mr">
    <long name="count">100</long>
    <double name="mcm">70829.5</double>
    <double name="mean">28.91</double>
    <double name="median">24.5</double>
    <double name="su">104076.0</double>
    <double name="sum">2891.0</double>
    <long name="unique">36</long>
  </lst>
  <lst name="cr">
    <str name="ccmax">this is the secondstr9</str>
    <str name="ccmin">this is the firststr0</str>
    <str name="csmax">this is the second</str>
    <str name="csmin">this is the first</str>
    <str name="max">str9</str>
    <str name="min">str0</str>
  </lst>
  <lst name="csr">
    <str name="cs1">this is the first</str>
    <str name="cs2">this is the second</str>
    <str name="cs3">this is the third</str>
  </lst>
</lst>
</response>

	at __randomizedtesting.SeedInfo.seed([F615C65BC2D2B6D7:396B85831DB190]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.analytics.AbstractAnalyticsStatsTest.getStatResult(AbstractAnalyticsStatsTest.java:114)
	at org.apache.solr.analytics.expression.ExpressionTest.addTest(ExpressionTest.java:78)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:613)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:780)


REGRESSION:  org.apache.solr.analytics.expression.ExpressionTest.negateTest

Error Message:
Caught exception in getStatResult, xPath = /response/lst[@name='stats']/lst[@name='nr']/double[@name='sum']  raw data: <?xml version="1.0" encoding="UTF-8"?> <response>  <lst name="responseHeader">   <int name="status">0</int>   <int name="QTime">4</int> </lst> <result name="response" numFound="100" start="0"> </result> <lst name="stats">   <lst name="stats_fields"/> </lst> <lst name="stats">   <lst name="ar">     <long name="count">100</long>     <null name="mcm"/>     <null name="mean"/>     <null name="median"/>     <null name="su"/>     <null name="sum"/>     <null name="unique"/>   </lst>   <lst name="dr">     <long name="count">100</long>     <double name="mc">0.2891</double>     <double name="mean">28.91</double>     <double name="su">80.30555555555556</double>     <double name="sum">2891.0</double>     <long name="unique">36</long>   </lst>   <lst name="rr">     <str name="max">str9</str>     <str name="min">str0</str>     <str name="rmax">9rts</str>     <str name="rmin">0rts</str>   </lst>   <lst name="cnr">     <double name="c10">10.0</double>     <double name="c8">8.0</double>   </lst>   <lst name="cdr">     <date name="cd1">1800-12-31T23:59:59Z</date>     <date name="cd2">1804-06-30T23:59:59Z</date>     <str name="cs1">1800-12-31T23:59:59Z</str>     <str name="cs2">1804-06-30T23:59:59Z</str>   </lst>   <lst name="dmr">     <str name="cma">+2MONTHS</str>     <str name="cme">+2YEARS</str>     <date name="dmma">1812-02-29T23:59:59Z</date>     <date name="dmme">1807-12-31T23:59:59Z</date>     <date name="max">1811-12-31T23:59:59Z</date>     <date name="median">1805-12-31T23:59:59Z</date>   </lst>   <lst name="pr">     <long name="count">100</long>     <double name="mc">1.2729436151389237E146</double>     <double name="mean">28.91</double>     <double name="su">3.9603293116911423E124</double>     <double name="sum">2891.0</double>     <long name="unique">36</long>   </lst>   <lst name="nr">     <double name="c">-100.0</double>     <long name="count">100</long>     <null name="s"/>     <null name="sum"/>   </lst>   <lst name="avr">     <double name="c">100.0</double>     <long name="count">100</long>     <double name="s">2891.0</double>     <double name="sum">2891.0</double>   </lst>   <lst name="mr">     <long name="count">100</long>     <double name="mcm">70829.5</double>     <double name="mean">28.91</double>     <double name="median">24.5</double>     <double name="su">104076.0</double>     <double name="sum">2891.0</double>     <long name="unique">36</long>   </lst>   <lst name="cr">     <str name="ccmax">this is the secondstr9</str>     <str name="ccmin">this is the firststr0</str>     <str name="csmax">this is the second</str>     <str name="csmin">this is the first</str>     <str name="max">str9</str>     <str name="min">str0</str>   </lst>   <lst name="csr">     <str name="cs1">this is the first</str>     <str name="cs2">this is the second</str>     <str name="cs3">this is the third</str>   </lst> </lst> </response> 

Stack Trace:
java.lang.AssertionError: Caught exception in getStatResult, xPath = /response/lst[@name='stats']/lst[@name='nr']/double[@name='sum'] 
raw data: <?xml version="1.0" encoding="UTF-8"?>
<response>

<lst name="responseHeader">
  <int name="status">0</int>
  <int name="QTime">4</int>
</lst>
<result name="response" numFound="100" start="0">
</result>
<lst name="stats">
  <lst name="stats_fields"/>
</lst>
<lst name="stats">
  <lst name="ar">
    <long name="count">100</long>
    <null name="mcm"/>
    <null name="mean"/>
    <null name="median"/>
    <null name="su"/>
    <null name="sum"/>
    <null name="unique"/>
  </lst>
  <lst name="dr">
    <long name="count">100</long>
    <double name="mc">0.2891</double>
    <double name="mean">28.91</double>
    <double name="su">80.30555555555556</double>
    <double name="sum">2891.0</double>
    <long name="unique">36</long>
  </lst>
  <lst name="rr">
    <str name="max">str9</str>
    <str name="min">str0</str>
    <str name="rmax">9rts</str>
    <str name="rmin">0rts</str>
  </lst>
  <lst name="cnr">
    <double name="c10">10.0</double>
    <double name="c8">8.0</double>
  </lst>
  <lst name="cdr">
    <date name="cd1">1800-12-31T23:59:59Z</date>
    <date name="cd2">1804-06-30T23:59:59Z</date>
    <str name="cs1">1800-12-31T23:59:59Z</str>
    <str name="cs2">1804-06-30T23:59:59Z</str>
  </lst>
  <lst name="dmr">
    <str name="cma">+2MONTHS</str>
    <str name="cme">+2YEARS</str>
    <date name="dmma">1812-02-29T23:59:59Z</date>
    <date name="dmme">1807-12-31T23:59:59Z</date>
    <date name="max">1811-12-31T23:59:59Z</date>
    <date name="median">1805-12-31T23:59:59Z</date>
  </lst>
  <lst name="pr">
    <long name="count">100</long>
    <double name="mc">1.2729436151389237E146</double>
    <double name="mean">28.91</double>
    <double name="su">3.9603293116911423E124</double>
    <double name="sum">2891.0</double>
    <long name="unique">36</long>
  </lst>
  <lst name="nr">
    <double name="c">-100.0</double>
    <long name="count">100</long>
    <null name="s"/>
    <null name="sum"/>
  </lst>
  <lst name="avr">
    <double name="c">100.0</double>
    <long name="count">100</long>
    <double name="s">2891.0</double>
    <double name="sum">2891.0</double>
  </lst>
  <lst name="mr">
    <long name="count">100</long>
    <double name="mcm">70829.5</double>
    <double name="mean">28.91</double>
    <double name="median">24.5</double>
    <double name="su">104076.0</double>
    <double name="sum">2891.0</double>
    <long name="unique">36</long>
  </lst>
  <lst name="cr">
    <str name="ccmax">this is the secondstr9</str>
    <str name="ccmin">this is the firststr0</str>
    <str name="csmax">this is the second</str>
    <str name="csmin">this is the first</str>
    <str name="max">str9</str>
    <str name="min">str0</str>
  </lst>
  <lst name="csr">
    <str name="cs1">this is the first</str>
    <str name="cs2">this is the second</str>
    <str name="cs3">this is the third</str>
  </lst>
</lst>
</response>

	at __randomizedtesting.SeedInfo.seed([F615C65BC2D2B6D7:FE1DAEFE66FFE667]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.analytics.AbstractAnalyticsStatsTest.getStatResult(AbstractAnalyticsStatsTest.java:114)
	at org.apache.solr.analytics.expression.ExpressionTest.negateTest(ExpressionTest.java:132)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:613)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:780)


REGRESSION:  org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.testMultiThreaded

Error Message:
expected:<1> but was:<2>

Stack Trace:
java.lang.AssertionError: expected:<1> but was:<2>
	at __randomizedtesting.SeedInfo.seed([F615C65BC2D2B6D7:97801CBB2A03BC21]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.failNotEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:128)
	at org.junit.Assert.assertEquals(Assert.java:472)
	at org.junit.Assert.assertEquals(Assert.java:456)
	at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.checkNumDocs(SignatureUpdateProcessorFactoryTest.java:71)
	at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.testMultiThreaded(SignatureUpdateProcessorFactoryTest.java:222)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:613)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:780)


REGRESSION:  org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.testDupeDetection

Error Message:
expected:<1> but was:<3>

Stack Trace:
java.lang.AssertionError: expected:<1> but was:<3>
	at __randomizedtesting.SeedInfo.seed([F615C65BC2D2B6D7:AD253D93C19515AB]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.failNotEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:128)
	at org.junit.Assert.assertEquals(Assert.java:472)
	at org.junit.Assert.assertEquals(Assert.java:456)
	at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.checkNumDocs(SignatureUpdateProcessorFactoryTest.java:71)
	at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.testDupeDetection(SignatureUpdateProcessorFactoryTest.java:119)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:613)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:780)




Build Log:
[...truncated 10329 lines...]
   [junit4] Suite: org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest
   [junit4]   2> 195394 T657 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
   [junit4]   2> 195395 T657 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1392857047843
   [junit4]   2> 195396 T657 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/'
   [junit4]   2> 195396 T657 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 195397 T657 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 195431 T657 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 195489 T657 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 195489 T657 oass.IndexSchema.readSchema Reading Solr Schema from schema12.xml
   [junit4]   2> 195495 T657 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 195851 T657 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 195853 T657 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 195854 T657 oass.IndexSchema.readSchema WARN Field text is not multivalued and destination for multiple copyFields (2)
   [junit4]   2> 195862 T657 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 195866 T657 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 195871 T657 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 195872 T657 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr
   [junit4]   2> 195872 T657 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/'
   [junit4]   2> 195915 T657 oasc.CoreContainer.<init> New CoreContainer -956043758
   [junit4]   2> 195916 T657 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/]
   [junit4]   2> 195916 T657 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 195917 T657 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 195917 T657 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 195917 T657 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 195918 T657 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 195918 T657 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 195918 T657 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 195919 T657 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 195919 T657 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 195924 T657 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 195924 T657 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 195925 T657 oasc.CoreContainer.load Host Name: 
   [junit4]   2> 195928 T658 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1
   [junit4]   2> 195928 T658 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/'
   [junit4]   2> 195929 T658 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 195929 T658 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 195970 T658 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 196035 T658 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 196036 T658 oass.IndexSchema.readSchema Reading Solr Schema from schema12.xml
   [junit4]   2> 196044 T658 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 196396 T658 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 196398 T658 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 196400 T658 oass.IndexSchema.readSchema WARN Field text is not multivalued and destination for multiple copyFields (2)
   [junit4]   2> 196406 T658 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 196409 T658 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 196413 T658 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 196413 T658 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1392857047843/
   [junit4]   2> 196414 T658 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1aff6c31
   [junit4]   2> 196414 T658 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1392857047843
   [junit4]   2> 196415 T658 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1392857047843/index/
   [junit4]   2> 196415 T658 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1392857047843/index' doesn't exist. Creating new index...
   [junit4]   2> 196415 T658 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1392857047843/index
   [junit4]   2> 196416 T658 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=44, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 196416 T658 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_1,generation=1}
   [junit4]   2> 196417 T658 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 196417 T658 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
   [junit4]   2> 196419 T658 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 196420 T658 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 196420 T658 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 196420 T658 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 196421 T658 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 196421 T658 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 196421 T658 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 196422 T658 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 196422 T658 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 196422 T658 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 196423 T658 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 196423 T658 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 196423 T658 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 196423 T658 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 196424 T658 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 196424 T658 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 196425 T658 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
   [junit4]   2> 196425 T658 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
   [junit4]   2> 196426 T658 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 196426 T658 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 196426 T658 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 196427 T658 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 196427 T658 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 196427 T658 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 196428 T658 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 196428 T658 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 196429 T658 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 196429 T658 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 196429 T658 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 196430 T658 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 196430 T658 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 196431 T658 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 196431 T658 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 196431 T658 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
   [junit4]   2> 196432 T658 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
   [junit4]   2> 196433 T658 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 196434 T658 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 196436 T658 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 196436 T658 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 196436 T658 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=22, maxMergedSegmentMB=39.2119140625, floorSegmentMB=0.58203125, forceMergeDeletesPctAllowed=17.945366200004937, segmentsPerTier=20.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 196437 T658 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_1,generation=1}
   [junit4]   2> 196437 T658 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 196438 T658 oass.SolrIndexSearcher.<init> Opening Searcher@acfaac5b[collection1] main
   [junit4]   2> 196438 T658 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 196493 T658 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 196522 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@acfaac5b[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 196527 T658 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 196529 T657 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 196532 T657 oas.SolrTestCaseJ4.setUp ###Starting testDupeAllFieldsDetection
   [junit4]   2> ASYNC  NEW_CORE C277 name=collection1 org.apache.solr.core.SolrCore@9afb55c
   [junit4]   2> 196533 T657 C277 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 196534 T657 C277 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
   [junit4]   2> 196537 T657 C277 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196538 T657 C277 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_2,generation=2}
   [junit4]   2> 196538 T657 C277 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 196539 T657 C277 oass.SolrIndexSearcher.<init> Opening Searcher@7e20bd7[collection1] main
   [junit4]   2> 196540 T657 C277 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196541 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7e20bd7[collection1] main{StandardDirectoryReader(segments_2:2:nrt)}
   [junit4]   2> 196542 T657 C277 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 196549 T657 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196551 T657 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_3,generation=3}
   [junit4]   2> 196551 T657 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
   [junit4]   2> 196553 T657 oass.SolrIndexSearcher.<init> Opening Searcher@9c8aa15c[collection1] main
   [junit4]   2> 196553 T657 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196555 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9c8aa15c[collection1] main{StandardDirectoryReader(segments_3:4:nrt _0(5.0):C3)}
   [junit4]   2> 196555 T657 oas.SolrTestCaseJ4.tearDown ###Ending testDupeAllFieldsDetection
   [junit4]   2> 196560 T657 oas.SolrTestCaseJ4.setUp ###Starting testMultiThreaded
   [junit4]   2> 196560 T657 C277 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 196561 T657 C277 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
   [junit4]   2> 196562 T657 C277 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196563 T657 C277 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_4,generation=4}
   [junit4]   2> 196564 T657 C277 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
   [junit4]   2> 196564 T657 C277 oass.SolrIndexSearcher.<init> Opening Searcher@db53cddc[collection1] main
   [junit4]   2> 196565 T657 C277 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196566 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@db53cddc[collection1] main{StandardDirectoryReader(segments_4:5:nrt)}
   [junit4]   2> 196567 T657 C277 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 196585 T670 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196605 T670 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_4,generation=4}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_5,generation=5}
   [junit4]   2> 196607 T670 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
   [junit4]   2> 196657 T670 oass.SolrIndexSearcher.<init> Opening Searcher@c0a8b48d[collection1] main
   [junit4]   2> 196665 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c0a8b48d[collection1] main{StandardDirectoryReader(segments_5:18:nrt _3(5.0):C18/16:delGen=1 _4(5.0):C31/30:delGen=1)}
   [junit4]   2> 196666 T670 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196666 T669 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196698 T669 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_5,generation=5}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_6,generation=6}
   [junit4]   2> 196699 T669 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
   [junit4]   2> 196720 T669 oass.SolrIndexSearcher.<init> Opening Searcher@92f6ccd8[collection1] main
   [junit4]   2> 196721 T669 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196722 T668 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196723 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@92f6ccd8[collection1] main{StandardDirectoryReader(segments_6:30:nrt _8(5.0):C31/28:delGen=1)}
   [junit4]   2> 196728 T668 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_6,generation=6}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_7,generation=7}
   [junit4]   2> 196728 T668 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 7
   [junit4]   2> 196733 T668 oass.SolrIndexSearcher.<init> Opening Searcher@7a47cd79[collection1] main
   [junit4]   2> 196734 T668 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196735 T670 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196735 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7a47cd79[collection1] main{StandardDirectoryReader(segments_7:40:nrt _b(5.0):C2/1:delGen=1 _c(5.0):C1)}
   [junit4]   2> 196736 T670 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_7,generation=7}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_8,generation=8}
   [junit4]   2> 196736 T670 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 8
   [junit4]   2> 196737 T670 oass.SolrIndexSearcher.<init> Opening Searcher@27b0d0d6[collection1] main
   [junit4]   2> 196738 T670 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196738 T669 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196739 T669 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 196739 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@27b0d0d6[collection1] main{StandardDirectoryReader(segments_7:40:nrt _b(5.0):C2/1:delGen=1 _c(5.0):C1)}
   [junit4]   2> 196742 T669 oass.SolrIndexSearcher.<init> Opening Searcher@4e00a536[collection1] main
   [junit4]   2> 196743 T669 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196743 T668 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196744 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4e00a536[collection1] main{StandardDirectoryReader(segments_8:45:nrt _b(5.0):C2/1:delGen=1 _d(5.0):C1)}
   [junit4]   2> 196748 T668 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_8,generation=8}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_9,generation=9}
   [junit4]   2> 196748 T668 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 9
   [junit4]   2> 196756 T668 oass.SolrIndexSearcher.<init> Opening Searcher@3280455d[collection1] main
   [junit4]   2> 196760 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3280455d[collection1] main{StandardDirectoryReader(segments_9:52:nrt _e(5.0):C1 _f(5.0):C1)}
   [junit4]   2> 196761 T668 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196762 T670 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196764 T670 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_9,generation=9}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_a,generation=10}
   [junit4]   2> 196764 T670 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 10
   [junit4]   2> 196767 T670 oass.SolrIndexSearcher.<init> Opening Searcher@8efe176b[collection1] main
   [junit4]   2> 196768 T670 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196769 T669 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196770 T669 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_a,generation=10}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_b,generation=11}
   [junit4]   2> 196771 T669 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 11
   [junit4]   2> 196771 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@8efe176b[collection1] main{StandardDirectoryReader(segments_a:58:nrt _g(5.0):C1)}
   [junit4]   2> 196772 T669 oass.SolrIndexSearcher.<init> Opening Searcher@c8100d40[collection1] main
   [junit4]   2> 196773 T669 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196773 T668 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196775 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c8100d40[collection1] main{StandardDirectoryReader(segments_a:58:nrt _g(5.0):C1)}
   [junit4]   2> 196778 T668 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_b,generation=11}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_c,generation=12}
   [junit4]   2> 196778 T668 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 12
   [junit4]   2> 196782 T668 oass.SolrIndexSearcher.<init> Opening Searcher@41686241[collection1] main
   [junit4]   2> 196782 T668 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196783 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@41686241[collection1] main{StandardDirectoryReader(segments_c:66:nrt _i(5.0):C1)}
   [junit4]   2> 196784 T670 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196785 T670 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_c,generation=12}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_d,generation=13}
   [junit4]   2> 196785 T670 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 13
   [junit4]   2> 196788 T670 oass.SolrIndexSearcher.<init> Opening Searcher@bb7b4fb7[collection1] main
   [junit4]   2> 196789 T670 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196790 T669 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196790 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@bb7b4fb7[collection1] main{StandardDirectoryReader(segments_d:70:nrt _j(5.0):C1)}
   [junit4]   2> 196790 T669 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_d,generation=13}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_e,generation=14}
   [junit4]   2> 196791 T669 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 14
   [junit4]   2> 196792 T669 oass.SolrIndexSearcher.<init> Opening Searcher@926c1a87[collection1] main
   [junit4]   2> 196793 T669 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196793 T668 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196794 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@926c1a87[collection1] main{StandardDirectoryReader(segments_d:70:nrt _j(5.0):C1)}
   [junit4]   2> 196798 T668 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_e,generation=14}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_f,generation=15}
   [junit4]   2> 196799 T668 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 15
   [junit4]   2> 196805 T668 oass.SolrIndexSearcher.<init> Opening Searcher@24499081[collection1] main
   [junit4]   2> 196806 T668 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196808 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@24499081[collection1] main{StandardDirectoryReader(segments_f:74:nrt _j(5.0):C1 _k(5.0):C1 _l(5.0):C1)}
   [junit4]   2> 196809 T670 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196811 T670 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_f,generation=15}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_g,generation=16}
   [junit4]   2> 196812 T670 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 16
   [junit4]   2> 196815 T670 oass.SolrIndexSearcher.<init> Opening Searcher@8b24c194[collection1] main
   [junit4]   2> 196821 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@8b24c194[collection1] main{StandardDirectoryReader(segments_g:80:nrt _j(5.0):C1 _m(5.0):C1)}
   [junit4]   2> 196822 T670 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196823 T669 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196824 T669 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_g,generation=16}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_h,generation=17}
   [junit4]   2> 196825 T669 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 17
   [junit4]   2> 196827 T669 oass.SolrIndexSearcher.<init> Opening Searcher@ef058afd[collection1] main
   [junit4]   2> 196828 T669 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196829 T668 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196829 T668 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 196830 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ef058afd[collection1] main{StandardDirectoryReader(segments_g:80:nrt _j(5.0):C1 _m(5.0):C1)}
   [junit4]   2> 196837 T668 oass.SolrIndexSearcher.<init> Opening Searcher@1fd5f6ca[collection1] main
   [junit4]   2> 196838 T668 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196840 T669 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196841 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1fd5f6ca[collection1] main{StandardDirectoryReader(segments_h:83:nrt _j(5.0):C1 _m(5.0):C1 _n(5.0):C1)}
   [junit4]   2> 196846 T669 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_h,generation=17}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_i,generation=18}
   [junit4]   2> 196847 T669 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 18
   [junit4]   2> 196851 T669 oass.SolrIndexSearcher.<init> Opening Searcher@5b69cced[collection1] main
   [junit4]   2> 196855 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5b69cced[collection1] main{StandardDirectoryReader(segments_i:88:nrt _j(5.0):C1 _m(5.0):C1 _p(5.0):C1)}
   [junit4]   2> 196856 T669 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196858 T670 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196859 T670 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_i,generation=18}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_j,generation=19}
   [junit4]   2> 196860 T670 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 19
   [junit4]   2> 196863 T670 oass.SolrIndexSearcher.<init> Opening Searcher@707bc7a0[collection1] main
   [junit4]   2> 196865 T670 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196866 T668 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196867 T668 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 196869 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@707bc7a0[collection1] main{StandardDirectoryReader(segments_i:88:nrt _j(5.0):C1 _m(5.0):C1 _p(5.0):C1)}
   [junit4]   2> 196876 T668 oass.SolrIndexSearcher.<init> Opening Searcher@65c67639[collection1] main
   [junit4]   2> 196877 T668 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196879 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@65c67639[collection1] main{StandardDirectoryReader(segments_j:91:nrt _j(5.0):C1 _m(5.0):C1 _p(5.0):C1 _q(5.0):C1)}
   [junit4]   2> 196880 T669 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196884 T669 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_j,generation=19}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_k,generation=20}
   [junit4]   2> 196884 T669 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 20
   [junit4]   2> 196887 T669 oass.SolrIndexSearcher.<init> Opening Searcher@c47608aa[collection1] main
   [junit4]   2> 196892 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c47608aa[collection1] main{StandardDirectoryReader(segments_k:98:nrt _m(5.0):C1 _s(5.0):C1)}
   [junit4]   2> 196893 T669 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196894 T670 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196895 T670 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_k,generation=20}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_l,generation=21}
   [junit4]   2> 196895 T670 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 21
   [junit4]   2> 196898 T670 oass.SolrIndexSearcher.<init> Opening Searcher@cbfcda6d[collection1] main
   [junit4]   2> 196899 T670 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196900 T668 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196901 T668 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_l,generation=21}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_m,generation=22}
   [junit4]   2> 196901 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@cbfcda6d[collection1] main{StandardDirectoryReader(segments_l:100:nrt _m(5.0):C1 _s(5.0):C1 _t(5.0):C1)}
   [junit4]   2> 196901 T668 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 22
   [junit4]   2> 196903 T668 oass.SolrIndexSearcher.<init> Opening Searcher@4875e7c[collection1] main
   [junit4]   2> 196903 T668 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196904 T669 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196904 T669 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 196905 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4875e7c[collection1] main{StandardDirectoryReader(segments_l:100:nrt _m(5.0):C1 _s(5.0):C1 _t(5.0):C1)}
   [junit4]   2> 196905 T669 oass.SolrIndexSearcher.<init> Opening Searcher@a25858c1[collection1] main
   [junit4]   2> 196906 T669 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196908 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@a25858c1[collection1] main{StandardDirectoryReader(segments_l:100:nrt _m(5.0):C1 _s(5.0):C1 _t(5.0):C1)}
   [junit4]   2> 196910 T668 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196918 T668 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_m,generation=22}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_n,generation=23}
   [junit4]   2> 196919 T668 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 23
   [junit4]   2> 196921 T668 oass.SolrIndexSearcher.<init> Opening Searcher@d2aad98a[collection1] main
   [junit4]   2> 196922 T668 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196924 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@d2aad98a[collection1] main{StandardDirectoryReader(segments_n:106:nrt _s(5.0):C1 _u(5.0):C2/1:delGen=1 _v(5.0):C1)}
   [junit4]   2> 196924 T670 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196925 T670 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 196926 T670 oass.SolrIndexSearcher.<init> Opening Searcher@f42f1091[collection1] main
   [junit4]   2> 196929 T670 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196930 T669 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196932 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f42f1091[collection1] main{StandardDirectoryReader(segments_n:106:nrt _s(5.0):C1 _u(5.0):C2/1:delGen=1 _v(5.0):C1)}
   [junit4]   2> 196933 T669 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_n,generation=23}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_o,generation=24}
   [junit4]   2> 196934 T669 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 24
   [junit4]   2> 196937 T669 oass.SolrIndexSearcher.<init> Opening Searcher@19d4bcae[collection1] main
   [junit4]   2> 196938 T669 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196939 T668 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196940 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@19d4bcae[collection1] main{StandardDirectoryReader(segments_o:114:nrt _s(5.0):C1 _x(5.0):C1)}
   [junit4]   2> 196940 T668 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_o,generation=24}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_p,generation=25}
   [junit4]   2> 196941 T668 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 25
   [junit4]   2> 196942 T668 oass.SolrIndexSearcher.<init> Opening Searcher@711c5a55[collection1] main
   [junit4]   2> 196943 T668 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196944 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@711c5a55[collection1] main{StandardDirectoryReader(segments_o:114:nrt _s(5.0):C1 _x(5.0):C1)}
   [junit4]   2> 196945 T670 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196948 T670 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_p,generation=25}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_q,generation=26}
   [junit4]   2> 196949 T670 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 26
   [junit4]   2> 196953 T670 oass.SolrIndexSearcher.<init> Opening Searcher@1174737a[collection1] main
   [junit4]   2> 196957 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1174737a[collection1] main{StandardDirectoryReader(segments_q:120:nrt _x(5.0):C1 _z(5.0):C1)}
   [junit4]   2> 196958 T670 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196959 T669 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196960 T669 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_q,generation=26}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_r,generation=27}
   [junit4]   2> 196961 T669 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 27
   [junit4]   2> 196964 T669 oass.SolrIndexSearcher.<init> Opening Searcher@479de143[collection1] main
   [junit4]   2> 196965 T669 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196965 T668 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196966 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@479de143[collection1] main{StandardDirectoryReader(segments_r:124:nrt _x(5.0):C1 _10(5.0):C1)}
   [junit4]   2> 196967 T668 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_r,generation=27}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_s,generation=28}
   [junit4]   2> 196968 T668 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 28
   [junit4]   2> 196969 T668 oass.SolrIndexSearcher.<init> Opening Searcher@d04405ad[collection1] main
   [junit4]   2> 196971 T668 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196972 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@d04405ad[collection1] main{StandardDirectoryReader(segments_r:124:nrt _x(5.0):C1 _10(5.0):C1)}
   [junit4]   2> 196973 T670 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196973 T670 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 196974 T670 oass.SolrIndexSearcher.<init> Opening Searcher@873a8542[collection1] main
   [junit4]   2> 196976 T670 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196978 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@873a8542[collection1] main{StandardDirectoryReader(segments_r:124:nrt _x(5.0):C1 _10(5.0):C1)}
   [junit4]   2> 196979 T657 C277 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196980 T657 C277 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 196981 T657 C277 oass.SolrIndexSearcher.<init> Opening Searcher@125678c9[collection1] main
   [junit4]   2> 196982 T657 C277 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 196984 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@125678c9[collection1] main{StandardDirectoryReader(segments_r:124:nrt _x(5.0):C1 _10(5.0):C1)}
   [junit4]   2> 196984 T657 C277 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 196987 T657 oas.SolrTestCaseJ4.tearDown ###Ending testMultiThreaded
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=SignatureUpdateProcessorFactoryTest -Dtests.method=testMultiThreaded -Dtests.seed=F615C65BC2D2B6D7 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=it_IT -Dtests.timezone=America/Ensenada -Dtests.file.encoding=UTF-8
   [junit4] FAILURE 0.44s J1 | SignatureUpdateProcessorFactoryTest.testMultiThreaded <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: expected:<1> but was:<2>
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([F615C65BC2D2B6D7:97801CBB2A03BC21]:0)
   [junit4]    > 	at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.checkNumDocs(SignatureUpdateProcessorFactoryTest.java:71)
   [junit4]    > 	at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.testMultiThreaded(SignatureUpdateProcessorFactoryTest.java:222)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:780)
   [junit4]   2> 196996 T657 oas.SolrTestCaseJ4.setUp ###Starting testFailNonIndexedSigWithOverwriteDupes
   [junit4]   2> 196997 T657 C277 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 196998 T657 C277 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
   [junit4]   2> 196999 T657 C277 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 197000 T657 C277 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_s,generation=28}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_t,generation=29}
   [junit4]   2> 197000 T657 C277 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 29
   [junit4]   2> 197001 T657 C277 oass.SolrIndexSearcher.<init> Opening Searcher@6ba16182[collection1] main
   [junit4]   2> 197002 T657 C277 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 197003 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6ba16182[collection1] main{StandardDirectoryReader(segments_t:125:nrt)}
   [junit4]   2> 197004 T657 C277 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 197006 T657 oas.SolrTestCaseJ4.tearDown ###Ending testFailNonIndexedSigWithOverwriteDupes
   [junit4]   2> 197010 T657 oas.SolrTestCaseJ4.setUp ###Starting testDupeDetection
   [junit4]   2> 197011 T657 C277 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 197012 T657 C277 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
   [junit4]   2> 197013 T657 C277 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 197014 T657 C277 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_t,generation=29}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_u,generation=30}
   [junit4]   2> 197014 T657 C277 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 30
   [junit4]   2> 197015 T657 C277 oass.SolrIndexSearcher.<init> Opening Searcher@c4130660[collection1] main
   [junit4]   2> 197016 T657 C277 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 197017 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c4130660[collection1] main{StandardDirectoryReader(segments_u:126:nrt)}
   [junit4]   2> 197018 T657 C277 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 5
   [junit4]   2> 197023 T657 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 197025 T657 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_u,generation=30}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_v,generation=31}
   [junit4]   2> 197026 T657 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 31
   [junit4]   2> 197026 T657 oass.SolrIndexSearcher.<init> Opening Searcher@99928d2a[collection1] main
   [junit4]   2> 197027 T657 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 197035 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@99928d2a[collection1] main{StandardDirectoryReader(segments_v:128:nrt _11(5.0):C2)}
   [junit4]   2> 197038 T657 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 197041 T657 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_v,generation=31}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@146dceb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d46f80d)),segFN=segments_w,generation=32}
   [junit4]   2> 197041 T657 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 32
   [junit4]   2> 197042 T657 oass.SolrIndexSearcher.<init> Opening Searcher@644f6da1[collection1] main
   [junit4]   2> 197043 T657 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 197044 T659 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@644f6da1[collection1] main{StandardDirectoryReader(segments_w:130:nrt _11(5.0):C2 _12(5.0):C1)}
   [junit4]   2> 197044 T657 oas.SolrTestCaseJ4.tearDown ###Ending testDupeDetection
   [

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

[junit4]    >   </lst>
   [junit4]    >   <lst name="mr">
   [junit4]    >     <long name="count">100</long>
   [junit4]    >     <double name="mcm">70829.5</double>
   [junit4]    >     <double name="mean">28.91</double>
   [junit4]    >     <double name="median">24.5</double>
   [junit4]    >     <double name="su">104076.0</double>
   [junit4]    >     <double name="sum">2891.0</double>
   [junit4]    >     <long name="unique">36</long>
   [junit4]    >   </lst>
   [junit4]    >   <lst name="cr">
   [junit4]    >     <str name="ccmax">this is the secondstr9</str>
   [junit4]    >     <str name="ccmin">this is the firststr0</str>
   [junit4]    >     <str name="csmax">this is the second</str>
   [junit4]    >     <str name="csmin">this is the first</str>
   [junit4]    >     <str name="max">str9</str>
   [junit4]    >     <str name="min">str0</str>
   [junit4]    >   </lst>
   [junit4]    >   <lst name="csr">
   [junit4]    >     <str name="cs1">this is the first</str>
   [junit4]    >     <str name="cs2">this is the second</str>
   [junit4]    >     <str name="cs3">this is the third</str>
   [junit4]    >   </lst>
   [junit4]    > </lst>
   [junit4]    > </response>
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([F615C65BC2D2B6D7:FE1DAEFE66FFE667]:0)
   [junit4]    > 	at org.apache.solr.analytics.AbstractAnalyticsStatsTest.getStatResult(AbstractAnalyticsStatsTest.java:114)
   [junit4]    > 	at org.apache.solr.analytics.expression.ExpressionTest.negateTest(ExpressionTest.java:132)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:780)
   [junit4]   2> 655469 T2831 oas.SolrTestCaseJ4.setUp ###Starting constantStringTest
   [junit4]   2> 655472 T2831 oas.SolrTestCaseJ4.tearDown ###Ending constantStringTest
   [junit4]   2> 655477 T2831 oas.SolrTestCaseJ4.setUp ###Starting divideTest
   [junit4]   2> 655481 T2831 oas.SolrTestCaseJ4.tearDown ###Ending divideTest
   [junit4]   2> 655486 T2831 oas.SolrTestCaseJ4.setUp ###Starting constantDateTest
   [junit4]   2> 655489 T2831 oas.SolrTestCaseJ4.tearDown ###Ending constantDateTest
   [junit4]   2> 655495 T2831 oas.SolrTestCaseJ4.setUp ###Starting reverseTest
   [junit4]   2> 655498 T2831 oas.SolrTestCaseJ4.tearDown ###Ending reverseTest
   [junit4]   2> 655500 T2831 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 655500 T2831 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1719579525
   [junit4]   2> 655500 T2831 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@a230604c
   [junit4]   2> 655501 T2831 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=97,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=100,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
   [junit4]   2> 655501 T2831 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 655501 T2831 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 655502 T2831 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 655502 T2831 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 655503 T2831 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 655503 T2831 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-ExpressionTest-1392857506391/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-ExpressionTest-1392857506391/index;done=false>>]
   [junit4]   2> 655504 T2831 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-ExpressionTest-1392857506391/index
   [junit4]   2> 655504 T2831 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-ExpressionTest-1392857506391 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-ExpressionTest-1392857506391;done=false>>]
   [junit4]   2> 655504 T2831 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-ExpressionTest-1392857506391
   [junit4]   2> NOTE: test params are: codec=HighCompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=500), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=500)), sim=DefaultSimilarity, locale=ar_LY, timezone=UCT
   [junit4]   2> NOTE: Linux 3.8.0-35-generic amd64/IBM Corporation 1.7.0 (64-bit)/cpus=8,threads=1,free=111945976,total=215023616
   [junit4]   2> NOTE: All tests run in this JVM: [JsonLoaderTest, SyncSliceTest, OverseerTest, ClusterStateTest, TestBadConfig, TestLRUCache, BasicDistributedZkTest, QueryElevationComponentTest, PolyFieldTest, TestBM25SimilarityFactory, TestFunctionQuery, PreAnalyzedUpdateProcessorTest, SimpleFacetsTest, SynonymTokenizerTest, FieldMutatingUpdateProcessorTest, TestSolrIndexConfig, FileBasedSpellCheckerTest, TestRealTimeGet, SliceStateTest, TestDocumentBuilder, TestSearchPerf, TestRandomDVFaceting, TestSchemaNameResource, SOLR749Test, DistributedSpellCheckComponentTest, ShowFileRequestHandlerTest, TestQueryUtils, TestElisionMultitermQuery, TestMergePolicyConfig, TestPerFieldSimilarity, DateMathParserTest, HdfsUnloadDistributedZkTest, TestNonDefinedSimilarityFactory, TestSimpleQParserPlugin, PrimitiveFieldTypeTest, TestLMJelinekMercerSimilarityFactory, TestDistribDocBasedVersion, TestCoreContainer, SolrInfoMBeanTest, TestMaxScoreQueryParser, DistributedSuggestComponentTest, TestLFUCache, TestPseudoReturnFields, TestDefaultSearchFieldResource, ScriptEngineTest, RangeFacetTest, TestUniqueKeyFieldResource, TestExtendedDismaxParser, TestLMDirichletSimilarityFactory, TestSurroundQueryParser, TestStressVersions, TestNonNRTOpen, EchoParamsTest, AnalysisAfterCoreReloadTest, URLClassifyProcessorTest, TestFieldTypeCollectionResource, DistribCursorPagingTest, TestPHPSerializedResponseWriter, MigrateRouteKeyTest, SpellPossibilityIteratorTest, HdfsCollectionsAPIDistributedZkTest, TermVectorComponentTest, LukeRequestHandlerTest, ResourceLoaderTest, CoreMergeIndexesAdminHandlerTest, TestStandardQParsers, UpdateParamsTest, LeaderElectionTest, BadCopyFieldTest, TestSolrXmlPersistence, OverseerCollectionProcessorTest, BadComponentTest, TestGroupingSearch, CacheHeaderTest, QueryParsingTest, BasicFunctionalityTest, DocValuesMissingTest, TestReplicationHandler, PeerSyncTest, BinaryUpdateRequestHandlerTest, CoreAdminCreateDiscoverTest, FieldFacetExtrasTest, TestSolrQueryParser, ReturnFieldsTest, StatelessScriptUpdateProcessorFactoryTest, SpatialFilterTest, AliasIntegrationTest, SearchHandlerTest, ShardRoutingTest, BasicZkTest, RecoveryZkTest, ClusterStateUpdateTest, ZkSolrClientTest, ZkCLITest, ShardRoutingCustomTest, SliceStateUpdateTest, TestFaceting, TermVectorComponentDistributedTest, ZkControllerTest, TestJoin, TestFiltering, DistributedQueryElevationComponentTest, CurrencyFieldXmlFileTest, SolrIndexSplitterTest, SuggesterFSTTest, CoreAdminHandlerTest, TestTrie, WordBreakSolrSpellCheckerTest, SchemaVersionSpecificBehaviorTest, TestWordDelimiterFilterFactory, QueryEqualityTest, TestRemoteStreaming, TestWriterPerf, TestOmitPositions, XmlUpdateRequestHandlerTest, DocumentBuilderTest, PathHierarchyTokenizerFactoryTest, MoreLikeThisHandlerTest, TestArbitraryIndexDir, IndexSchemaRuntimeFieldTest, RegexBoostProcessorTest, TestJmxIntegration, JSONWriterTest, UniqFieldsUpdateProcessorFactoryTest, CSVRequestHandlerTest, TestQuerySenderNoQuery, ResponseLogComponentTest, SampleTest, TestBinaryField, MinimalSchemaTest, ExternalFileFieldSortTest, NotRequiredUniqueKeyTest, TestPhraseSuggestions, TestXIncludeConfig, TestDefaultSimilarityFactory, LegacyHTMLStripCharFilterTest, TimeZoneUtilsTest, ChaosMonkeyNothingIsSafeTest, PreAnalyzedFieldTest, TestSolrJ, CircularListTest, TestRTGBase, SolrTestCaseJ4Test, TestHighlightDedupGrouping, AbstractAnalyticsStatsTest, NoFacetTest, ExpressionTest]
   [junit4] Completed on J0 in 1.50s, 12 tests, 2 failures <<< FAILURES!

[...truncated 188 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:453: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:446: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1268: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:901: There were test failures: 372 suites, 1604 tests, 4 failures, 72 ignored (7 assumptions)

Total time: 35 minutes 12 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_60-ea-b04) - Build # 9532 - Still Failing!

Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9532/
Java: 32bit/jdk1.7.0_60-ea-b04 -client -XX:+UseG1GC

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

Error Message:
Suite timeout exceeded (>= 7200000 msec).

Stack Trace:
java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
	at __randomizedtesting.SeedInfo.seed([E6427C4D79E850F1]:0)


FAILED:  org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch

Error Message:
Test abandoned because suite timeout was reached.

Stack Trace:
java.lang.Exception: Test abandoned because suite timeout was reached.
	at __randomizedtesting.SeedInfo.seed([E6427C4D79E850F1]:0)




Build Log:
[...truncated 10981 lines...]
   [junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
   [junit4]   2> 294403 T739 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
   [junit4]   2> 294403 T739 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /g/jw
   [junit4]   2> 294407 T739 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-ChaosMonkeySafeLeaderTest-1392862966525
   [junit4]   2> 294408 T739 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 294408 T740 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 294508 T739 oasc.ZkTestServer.run start zk server on port:43367
   [junit4]   2> 294509 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 294542 T746 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1dcfc13 name:ZooKeeperConnection Watcher:127.0.0.1:43367 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 294542 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 294542 T739 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 294546 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 294548 T748 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b65496 name:ZooKeeperConnection Watcher:127.0.0.1:43367/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 294548 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 294549 T739 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 294551 T739 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 294553 T739 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 294555 T739 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 294558 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 294559 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 294599 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 294600 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 294637 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 294638 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 294641 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 294642 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 294644 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 294645 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 294649 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 294649 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 294651 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 294652 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 294654 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 294655 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 294657 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 294658 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 294660 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 294661 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 294663 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 294664 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 294757 T739 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 294760 T739 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57963
   [junit4]   2> 294760 T739 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 294761 T739 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 294761 T739 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392862966792
   [junit4]   2> 294762 T739 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392862966792/'
   [junit4]   2> 294774 T739 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392862966792/solr.xml
   [junit4]   2> 294850 T739 oasc.CoreContainer.<init> New CoreContainer 21186385
   [junit4]   2> 294851 T739 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392862966792/]
   [junit4]   2> 294852 T739 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 294853 T739 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 294853 T739 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 294854 T739 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 294854 T739 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 294854 T739 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 294855 T739 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 294855 T739 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 294855 T739 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 294858 T739 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 294858 T739 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 294858 T739 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 294859 T739 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43367/solr
   [junit4]   2> 294859 T739 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 294860 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 294861 T759 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ff4bcd name:ZooKeeperConnection Watcher:127.0.0.1:43367 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 294862 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 294864 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 294865 T761 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a7f33 name:ZooKeeperConnection Watcher:127.0.0.1:43367/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 294865 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 294867 T739 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 294869 T739 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 294872 T739 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 294873 T739 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57963_g%2Fjw
   [junit4]   2> 294885 T739 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57963_g%2Fjw
   [junit4]   2> 294900 T739 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 294902 T739 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 294906 T739 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57963_g%2Fjw
   [junit4]   2> 294906 T739 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 294908 T739 oasc.Overseer.start Overseer (id=91282667374379011-127.0.0.1:57963_g%2Fjw-n_0000000000) starting
   [junit4]   2> 294911 T739 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 294913 T763 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 294915 T739 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 294915 T763 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 294918 T739 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 294921 T739 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 294924 T762 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 294927 T764 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 294928 T764 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 294929 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 294929 T764 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 294930 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 294931 T762 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:57963/g/jw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57963_g%2Fjw",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 294931 T762 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 294931 T762 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 294933 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 294934 T761 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> 295930 T764 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 295930 T764 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392862966792/collection1
   [junit4]   2> 295930 T764 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 295931 T764 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 295931 T764 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 295932 T764 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 295932 T764 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392862966792/collection1/'
   [junit4]   2> 295933 T764 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392862966792/collection1/lib/classes/' to classloader
   [junit4]   2> 295933 T764 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392862966792/collection1/lib/README' to classloader
   [junit4]   2> 295964 T764 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 295994 T764 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 295995 T764 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 296003 T764 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 296284 T764 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 296287 T764 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 296288 T764 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 296291 T764 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 296308 T764 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 296314 T764 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392862966792/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/control/data/
   [junit4]   2> 296314 T764 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@14290e2
   [junit4]   2> 296315 T764 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/control/data
   [junit4]   2> 296315 T764 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/control/data/index/
   [junit4]   2> 296315 T764 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 296316 T764 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/control/data/index
   [junit4]   2> 296316 T764 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=26, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.42302593417648215]
   [junit4]   2> 296319 T764 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/control/data/index,segFN=segments_1,generation=1}
   [junit4]   2> 296320 T764 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 296322 T764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 296323 T764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 296323 T764 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 296323 T764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 296323 T764 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 296323 T764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 296324 T764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 296324 T764 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 296324 T764 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 296325 T764 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 296325 T764 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 296325 T764 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 296326 T764 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 296326 T764 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 296326 T764 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 296327 T764 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 296327 T764 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 296330 T764 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 296332 T764 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 296332 T764 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 296332 T764 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=96.0458984375, floorSegmentMB=0.5322265625, forceMergeDeletesPctAllowed=0.6630555922421633, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6832137714827566
   [junit4]   2> 296333 T764 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/control/data/index,segFN=segments_1,generation=1}
   [junit4]   2> 296334 T764 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 296334 T764 oass.SolrIndexSearcher.<init> Opening Searcher@696108[collection1] main
   [junit4]   2> 296338 T764 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 296339 T739 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 296339 T739 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 296339 T765 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@696108[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 296339 T768 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57963/g/jw collection:control_collection shard:shard1
   [junit4]   2> 296341 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 296342 T770 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b8f229 name:ZooKeeperConnection Watcher:127.0.0.1:43367/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 296342 T768 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 296342 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 296344 T739 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 296346 T739 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 296348 T768 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 296350 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 296350 T768 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 296351 T768 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C328 name=collection1 org.apache.solr.core.SolrCore@2f9923 url=http://127.0.0.1:57963/g/jw/collection1 node=127.0.0.1:57963_g%2Fjw C328_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:57963/g/jw, core=collection1, node_name=127.0.0.1:57963_g%2Fjw}
   [junit4]   2> 296351 T768 C328 P57963 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57963/g/jw/collection1/
   [junit4]   2> 296351 T768 C328 P57963 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 296351 T768 C328 P57963 oasc.SyncStrategy.syncToMe http://127.0.0.1:57963/g/jw/collection1/ has no replicas
   [junit4]   2> 296352 T768 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57963/g/jw/collection1/ shard1
   [junit4]   2> 296352 T768 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 296353 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 296359 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 296362 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 296365 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 296434 T739 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 296435 T739 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 296436 T739 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:39275
   [junit4]   2> 296437 T739 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 296437 T739 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 296439 T739 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392862968465
   [junit4]   2> 296439 T739 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392862968465/'
   [junit4]   2> 296451 T739 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392862968465/solr.xml
   [junit4]   2> 296468 T770 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> 296468 T761 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> 296482 T739 oasc.CoreContainer.<init> New CoreContainer 30577886
   [junit4]   2> 296482 T739 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392862968465/]
   [junit4]   2> 296483 T739 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 296484 T739 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 296484 T739 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 296484 T739 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 296484 T739 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 296485 T739 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 296485 T739 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 296485 T739 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 296486 T739 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 296488 T739 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 296488 T739 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 296489 T739 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 296489 T739 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43367/solr
   [junit4]   2> 296489 T739 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 296490 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 296492 T781 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ba3c3 name:ZooKeeperConnection Watcher:127.0.0.1:43367 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 296492 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 296494 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 296495 T783 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11ce827 name:ZooKeeperConnection Watcher:127.0.0.1:43367/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 296495 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 296499 T739 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 296513 T768 oasc.ZkController.register We are http://127.0.0.1:57963/g/jw/collection1/ and leader is http://127.0.0.1:57963/g/jw/collection1/
   [junit4]   2> 296513 T768 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57963/g/jw
   [junit4]   2> 296513 T768 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 296513 T768 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 296514 T768 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 296515 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 296515 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 296515 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 296515 T768 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 296517 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 296518 T762 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:57963/g/jw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57963_g%2Fjw",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 296520 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 296623 T783 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> 296623 T761 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> 296623 T770 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> 297501 T739 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39275_g%2Fjw
   [junit4]   2> 297503 T739 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39275_g%2Fjw
   [junit4]   2> 297506 T761 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 297506 T783 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 297506 T770 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 297512 T784 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 297512 T784 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 297513 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 297513 T784 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 297513 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 297514 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 297515 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 297515 T762 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:39275/g/jw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:39275_g%2Fjw",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 297515 T762 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 297516 T762 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 297518 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 297667 T783 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> 297667 T761 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> 297667 T770 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> 298514 T784 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 298514 T784 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392862968465/collection1
   [junit4]   2> 298514 T784 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 298515 T784 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 298515 T784 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 298516 T784 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 298517 T784 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392862968465/collection1/'
   [junit4]   2> 298517 T784 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392862968465/collection1/lib/classes/' to classloader
   [junit4]   2> 298518 T784 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392862968465/collection1/lib/README' to classloader
   [junit4]   2> 298550 T784 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 298579 T784 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 298580 T784 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 298588 T784 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 298892 T784 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 298895 T784 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 298896 T784 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 298900 T784 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 298918 T784 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 298918 T784 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392862968465/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty1/
   [junit4]   2> 298919 T784 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@14290e2
   [junit4]   2> 298919 T784 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty1
   [junit4]   2> 298919 T784 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty1/index/
   [junit4]   2> 298920 T784 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 298921 T784 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty1/index
   [junit4]   2> 298921 T784 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=26, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.42302593417648215]
   [junit4]   2> 298950 T784 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty1/index,segFN=segments_1,generation=1}
   [junit4]   2> 298951 T784 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 298954 T784 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 298954 T784 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 298954 T784 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 298955 T784 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 298955 T784 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 298955 T784 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 298955 T784 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 298956 T784 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 298956 T784 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 298957 T784 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 298957 T784 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 298957 T784 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 298958 T784 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 298958 T784 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 298958 T784 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 298959 T784 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 298960 T784 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 298962 T784 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 298964 T784 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 298964 T784 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 298965 T784 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=96.0458984375, floorSegmentMB=0.5322265625, forceMergeDeletesPctAllowed=0.6630555922421633, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6832137714827566
   [junit4]   2> 298966 T784 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty1/index,segFN=segments_1,generation=1}
   [junit4]   2> 298966 T784 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 298967 T784 oass.SolrIndexSearcher.<init> Opening Searcher@98cb7b[collection1] main
   [junit4]   2> 298971 T785 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@98cb7b[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 298974 T784 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 298975 T739 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 298976 T739 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 298975 T788 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:39275/g/jw collection:collection1 shard:shard1
   [junit4]   2> 298977 T788 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 298983 T788 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 298984 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 298985 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 298985 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 298985 T788 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 298986 T788 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C329 name=collection1 org.apache.solr.core.SolrCore@bcc86c url=http://127.0.0.1:39275/g/jw/collection1 node=127.0.0.1:39275_g%2Fjw C329_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:39275/g/jw, core=collection1, node_name=127.0.0.1:39275_g%2Fjw}
   [junit4]   2> 298986 T788 C329 P39275 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:39275/g/jw/collection1/
   [junit4]   2> 298986 T788 C329 P39275 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 298986 T788 C329 P39275 oasc.SyncStrategy.syncToMe http://127.0.0.1:39275/g/jw/collection1/ has no replicas
   [junit4]   2> 298987 T788 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:39275/g/jw/collection1/ shard1
   [junit4]   2> 298987 T788 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 298988 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 298991 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 298993 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 298997 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 299080 T739 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 299081 T739 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 299083 T739 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:37755
   [junit4]   2> 299084 T739 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 299084 T739 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 299085 T739 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392862971094
   [junit4]   2> 299085 T739 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392862971094/'
   [junit4]   2> 299098 T739 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392862971094/solr.xml
   [junit4]   2> 299099 T761 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> 299099 T770 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> 299100 T783 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> 299138 T739 oasc.CoreContainer.<init> New CoreContainer 7548654
   [junit4]   2> 299138 T739 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392862971094/]
   [junit4]   2> 299139 T739 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 299139 T739 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 299140 T739 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 299140 T739 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 299141 T739 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 299141 T739 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 299141 T739 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 299142 T739 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 299142 T739 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 299144 T739 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 299144 T788 oasc.ZkController.register We are http://127.0.0.1:39275/g/jw/collection1/ and leader is http://127.0.0.1:39275/g/jw/collection1/
   [junit4]   2> 299145 T739 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 299145 T788 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39275/g/jw
   [junit4]   2> 299146 T788 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 299146 T788 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 299146 T788 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 299146 T739 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 299147 T739 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43367/solr
   [junit4]   2> 299147 T739 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 299148 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 299157 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 299157 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 299157 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 299159 T799 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@121a462 name:ZooKeeperConnection Watcher:127.0.0.1:43367 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 299159 T788 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 299160 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 299160 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 299162 T762 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:39275/g/jw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:39275_g%2Fjw",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 299163 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 299164 T801 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e9f4c9 name:ZooKeeperConnection Watcher:127.0.0.1:43367/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 299164 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 299165 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 299168 T739 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 299279 T801 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> 299279 T783 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> 299279 T770 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> 299279 T761 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> 300172 T739 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37755_g%2Fjw
   [junit4]   2> 300174 T739 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37755_g%2Fjw
   [junit4]   2> 300178 T783 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 300178 T770 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 300178 T761 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 300179 T801 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 300184 T802 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 300185 T802 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 300186 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 300186 T802 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 300186 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 300186 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 300188 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 300188 T762 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:37755/g/jw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:37755_g%2Fjw",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 300189 T762 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 300189 T762 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 300191 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 300347 T801 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> 300347 T770 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> 300347 T783 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> 300347 T761 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> 301186 T802 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 301187 T802 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392862971094/collection1
   [junit4]   2> 301187 T802 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 301188 T802 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 301188 T802 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 301189 T802 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 301189 T802 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392862971094/collection1/'
   [junit4]   2> 301190 T802 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392862971094/collection1/lib/classes/' to classloader
   [junit4]   2> 301191 T802 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392862971094/collection1/lib/README' to classloader
   [junit4]   2> 301237 T802 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 301273 T802 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 301274 T802 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 301282 T802 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 301549 T802 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 301551 T802 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 301553 T802 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 301556 T802 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 301573 T802 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 301574 T802 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392862971094/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty2/
   [junit4]   2> 301574 T802 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@14290e2
   [junit4]   2> 301574 T802 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty2
   [junit4]   2> 301575 T802 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty2/index/
   [junit4]   2> 301575 T802 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 301575 T802 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty2/index
   [junit4]   2> 301576 T802 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=26, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.42302593417648215]
   [junit4]   2> 301579 T802 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty2/index,segFN=segments_1,generation=1}
   [junit4]   2> 301579 T802 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 301582 T802 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 301583 T802 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 301583 T802 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 301583 T802 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 301583 T802 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 301584 T802 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 301584 T802 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 301584 T802 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 301584 T802 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 301585 T802 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 301586 T802 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 301586 T802 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 301586 T802 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 301587 T802 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 301587 T802 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 301587 T802 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 301588 T802 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 301590 T802 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 301592 T802 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 301593 T802 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 301594 T802 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=96.0458984375, floorSegmentMB=0.5322265625, forceMergeDeletesPctAllowed=0.6630555922421633, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6832137714827566
   [junit4]   2> 301595 T802 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty2/index,segFN=segments_1,generation=1}
   [junit4]   2> 301595 T802 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 301595 T802 oass.SolrIndexSearcher.<init> Opening Searcher@caf6bf[collection1] main
   [junit4]   2> 301600 T803 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@caf6bf[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 301603 T802 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 301604 T739 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 301604 T739 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 301604 T806 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:37755/g/jw collection:collection1 shard:shard2
   [junit4]   2> 301606 T806 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 301611 T806 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 301613 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301614 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301614 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301615 T806 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 301615 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 301615 T806 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C330 name=collection1 org.apache.solr.core.SolrCore@25570e url=http://127.0.0.1:37755/g/jw/collection1 node=127.0.0.1:37755_g%2Fjw C330_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:37755/g/jw, core=collection1, node_name=127.0.0.1:37755_g%2Fjw}
   [junit4]   2> 301616 T806 C330 P37755 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:37755/g/jw/collection1/
   [junit4]   2> 301616 T806 C330 P37755 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 301617 T806 C330 P37755 oasc.SyncStrategy.syncToMe http://127.0.0.1:37755/g/jw/collection1/ has no replicas
   [junit4]   2> 301617 T806 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:37755/g/jw/collection1/ shard2
   [junit4]   2> 301617 T806 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 301619 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301622 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301625 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301693 T739 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 301694 T739 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 301696 T739 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:46294
   [junit4]   2> 301697 T739 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 301697 T739 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 301697 T739 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392862973723
   [junit4]   2> 301698 T739 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392862973723/'
   [junit4]   2> 301711 T739 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392862973723/solr.xml
   [junit4]   2> 301729 T761 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> 301729 T801 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> 301729 T783 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> 301729 T770 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> 301757 T739 oasc.CoreContainer.<init> New CoreContainer 6612675
   [junit4]   2> 301757 T739 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392862973723/]
   [junit4]   2> 301759 T739 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 301759 T739 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 301760 T739 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 301760 T739 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 301761 T739 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 301761 T739 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 301762 T739 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 301762 T739 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 301763 T739 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 301765 T739 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 301765 T739 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 301766 T739 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 301766 T739 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43367/solr
   [junit4]   2> 301766 T739 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 301767 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 301769 T817 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6a1bcb name:ZooKeeperConnection Watcher:127.0.0.1:43367 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 301770 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 301772 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 301774 T806 oasc.ZkController.register We are http://127.0.0.1:37755/g/jw/collection1/ and leader is http://127.0.0.1:37755/g/jw/collection1/
   [junit4]   2> 301774 T806 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:37755/g/jw
   [junit4]   2> 301774 T819 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d3d9ce name:ZooKeeperConnection Watcher:127.0.0.1:43367/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 301774 T806 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 301774 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 301774 T806 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 301775 T806 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 301777 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301777 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301777 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301777 T806 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 301779 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 301779 T762 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:37755/g/jw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:37755_g%2Fjw",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 301781 T739 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 301782 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301885 T770 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> 301885 T783 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> 301885 T801 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> 301885 T761 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> 301885 T819 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> 302785 T739 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46294_g%2Fjw
   [junit4]   2> 302786 T739 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46294_g%2Fjw
   [junit4]   2> 302789 T770 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 302789 T801 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 302790 T819 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 302790 T761 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 302789 T783 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 302796 T820 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 302796 T820 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 302798 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 302798 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 302798 T820 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 302798 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 302799 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 302800 T762 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:46294/g/jw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:46294_g%2Fjw",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 302800 T762 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 302800 T762 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 302859 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 302962 T783 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 302962 T761 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 302962 T770 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 302962 T801 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 302962 T819 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 303798 T820 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 303799 T820 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392862973723/collection1
   [junit4]   2> 303799 T820 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 303800 T820 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 303800 T820 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 303802 T820 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 303802 T820 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392862973723/collection1/'
   [junit4]   2> 303803 T820 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392862973723/collection1/lib/classes/' to classloader
   [junit4]   2> 303803 T820 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392862973723/collection1/lib/README' to classloader
   [junit4]   2> 303848 T820 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 303877 T820 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 303879 T820 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 303887 T820 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 304159 T820 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 304162 T820 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 304163 T820 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 304166 T820 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 304185 T820 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 304185 T820 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392862973723/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty3/
   [junit4]   2> 304185 T820 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@14290e2
   [junit4]   2> 304186 T820 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty3
   [junit4]   2> 304186 T820 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty3/index/
   [junit4]   2> 304186 T820 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 304187 T820 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty3/index
   [junit4]   2> 304188 T820 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=26, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.42302593417648215]
   [junit4]   2> 304190 T820 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty3/index,segFN=segments_1,generation=1}
   [junit4]   2> 304191 T820 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 304194 T820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 304194 T820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 304194 T820 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 304195 T820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 304195 T820 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 304195 T820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 304195 T820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 304196 T820 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 304196 T820 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 304197 T820 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 304197 T820 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 304197 T820 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 304198 T820 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 304198 T820 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 304198 T820 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 304199 T820 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 304200 T820 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 304202 T820 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 304204 T820 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 304204 T820 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 304205 T820 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=96.0458984375, floorSegmentMB=0.5322265625, forceMergeDeletesPctAllowed=0.6630555922421633, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6832137714827566
   [junit4]   2> 304206 T820 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty3/index,segFN=segments_1,generation=1}
   [junit4]   2> 304206 T820 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 304207 T820 oass.SolrIndexSearcher.<init> Opening Searcher@1d7f550[collection1] main
   [junit4]   2> 304211 T821 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1d7f550[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 304214 T820 oasc.CoreContainer.regi

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

  [junit4]   2> 	        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:78)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
   [junit4]   2> 	        at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:569)
   [junit4]   2> 	        at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 	  68) Thread[id=840, name=Thread-341, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at java.lang.Object.wait(Native Method)
   [junit4]   2> 	        at java.lang.Object.wait(Object.java:503)
   [junit4]   2> 	        at org.apache.solr.core.CloserThread.run(CoreContainer.java:1018)
   [junit4]   2> 	  69) Thread[id=1072, name=qtp18553588-1072 Acceptor0 SelectChannelConnector@127.0.0.1:49910, state=BLOCKED, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at org.eclipse.jetty.server.nio.SelectChannelConnector.accept(SelectChannelConnector.java:102)
   [junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:938)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 	  70) Thread[id=1050, name=Thread-440-SendThread(localhost.localdomain:43367), state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at java.lang.Thread.sleep(Native Method)
   [junit4]   2> 	        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:984)
   [junit4]   2> 	  71) Thread[id=907, name=qtp30589138-907 Acceptor1 SelectChannelConnector@127.0.0.1:59940, state=BLOCKED, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at org.eclipse.jetty.server.nio.SelectChannelConnector.getConnection(SelectChannelConnector.java:160)
   [junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:934)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 	  72) Thread[id=883, name=HashSessionScavenger-18, state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at java.lang.Object.wait(Native Method)
   [junit4]   2> 	        at java.util.TimerThread.mainLoop(Timer.java:552)
   [junit4]   2> 	        at java.util.TimerThread.run(Timer.java:505)
   [junit4]   2> 	  73) Thread[id=1013, name=commitScheduler-591-thread-1, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at sun.misc.Unsafe.park(Native Method)
   [junit4]   2> 	        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
   [junit4]   2> 	        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
   [junit4]   2> 	        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1079)
   [junit4]   2> 	        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 	  74) Thread[id=1086, name=Thread-472, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at java.lang.Object.wait(Native Method)
   [junit4]   2> 	        at java.lang.Object.wait(Object.java:503)
   [junit4]   2> 	        at org.apache.solr.core.CloserThread.run(CoreContainer.java:1018)
   [junit4]   2> 	  75) Thread[id=966, name=qtp1966647-966 Acceptor0 SelectChannelConnector@127.0.0.1:52162, state=BLOCKED, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at org.eclipse.jetty.server.nio.SelectChannelConnector.accept(SelectChannelConnector.java:102)
   [junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:938)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 	  76) Thread[id=886, name=qtp517760-886 Acceptor0 SelectChannelConnector@127.0.0.1:58203, state=BLOCKED, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at org.eclipse.jetty.server.nio.SelectChannelConnector.accept(SelectChannelConnector.java:102)
   [junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:938)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 	  77) Thread[id=826, name=qtp32456852-826 Selector0, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
   [junit4]   2> 	        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
   [junit4]   2> 	        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
   [junit4]   2> 	        at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:569)
   [junit4]   2> 	        at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> NOTE: test params are: codec=Lucene42, sim=DefaultSimilarity, locale=ar_SA, timezone=America/Aruba
   [junit4]   2> NOTE: Linux 3.8.0-35-generic i386/Oracle Corporation 1.7.0_60-ea (32-bit)/cpus=8,threads=90,free=199087048,total=324009984
   [junit4]   2> NOTE: All tests run in this JVM: [ShardSplitTest, UniqFieldsUpdateProcessorFactoryTest, DisMaxRequestHandlerTest, StandardRequestHandlerTest, TestPartialUpdateDeduplication, TestFieldTypeCollectionResource, CachingDirectoryFactoryTest, TestIndexingPerformance, LeaderElectionIntegrationTest, HdfsCollectionsAPIDistributedZkTest, TestReloadAndDeleteDocs, TestNonDefinedSimilarityFactory, DirectSolrSpellCheckerTest, TestBinaryResponseWriter, SolrPluginUtilsTest, PreAnalyzedFieldTest, TestCSVResponseWriter, DistributedQueryComponentCustomSortTest, ConvertedLegacyTest, ZkSolrClientTest, TestIBSimilarityFactory, TestFastWriter, TestSolrCoreProperties, TimeZoneUtilsTest, TestCoreDiscovery, TestXIncludeConfig, TestIndexSearcher, TestCollationFieldDocValues, ChaosMonkeySafeLeaderTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.seed=E6427C4D79E850F1 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ar_SA -Dtests.timezone=America/Aruba -Dtests.file.encoding=UTF-8
   [junit4] ERROR   0.00s J1 | ChaosMonkeySafeLeaderTest (suite) <<<
   [junit4]    > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([E6427C4D79E850F1]:0)
   [junit4] Completed on J1 in 7225.32s, 1 test, 2 errors <<< FAILURES!

[...truncated 203 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:453: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:433: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1268: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:901: There were test failures: 372 suites, 1604 tests, 1 suite-level error, 1 error, 254 ignored (5 assumptions)

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