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 2013/12/04 02:31:52 UTC
[JENKINS] Lucene-Solr-trunk-Linux (64bit/ibm-j9-jdk7) - Build #
8562 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/8562/
Java: 64bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
6 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">7</int> </lst> <result name="response" numFound="100" start="0"> </result> <lst name="stats"> <lst name="stats_fields"/> </lst> <lst name="stats"> <lst name="avr"> <double name="c">100.0</double> <long name="count">100</long> <null name="s"/> <null name="sum"/> </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="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="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="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="pr"> <long name="count">100</long> <null name="mc"/> <null name="mean"/> <null name="su"/> <null name="sum"/> <null name="unique"/> </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="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 name="nr"> <double name="c">-100.0</double> <long name="count">100</long> <null name="s"/> <null name="sum"/> </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="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> </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">7</int>
</lst>
<result name="response" numFound="100" start="0">
</result>
<lst name="stats">
<lst name="stats_fields"/>
</lst>
<lst name="stats">
<lst name="avr">
<double name="c">100.0</double>
<long name="count">100</long>
<null name="s"/>
<null name="sum"/>
</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="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="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="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="pr">
<long name="count">100</long>
<null name="mc"/>
<null name="mean"/>
<null name="su"/>
<null name="sum"/>
<null name="unique"/>
</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="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 name="nr">
<double name="c">-100.0</double>
<long name="count">100</long>
<null name="s"/>
<null name="sum"/>
</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="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>
</response>
at __randomizedtesting.SeedInfo.seed([4AC03F1DF99E362A:BCEC92C3B851316D]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.analytics.AbstractAnalyticsStatsTest.getStatResult(AbstractAnalyticsStatsTest.java:113)
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.powerTest
Error Message:
Caught exception in getStatResult, xPath = /response/lst[@name='stats']/lst[@name='pr']/double[@name='sum'] raw data: <?xml version="1.0" encoding="UTF-8"?> <response> <lst name="responseHeader"> <int name="status">0</int> <int name="QTime">7</int> </lst> <result name="response" numFound="100" start="0"> </result> <lst name="stats"> <lst name="stats_fields"/> </lst> <lst name="stats"> <lst name="avr"> <double name="c">100.0</double> <long name="count">100</long> <null name="s"/> <null name="sum"/> </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="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="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="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="pr"> <long name="count">100</long> <null name="mc"/> <null name="mean"/> <null name="su"/> <null name="sum"/> <null name="unique"/> </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="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 name="nr"> <double name="c">-100.0</double> <long name="count">100</long> <null name="s"/> <null name="sum"/> </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="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> </response>
Stack Trace:
java.lang.AssertionError: Caught exception in getStatResult, xPath = /response/lst[@name='stats']/lst[@name='pr']/double[@name='sum']
raw data: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader">
<int name="status">0</int>
<int name="QTime">7</int>
</lst>
<result name="response" numFound="100" start="0">
</result>
<lst name="stats">
<lst name="stats_fields"/>
</lst>
<lst name="stats">
<lst name="avr">
<double name="c">100.0</double>
<long name="count">100</long>
<null name="s"/>
<null name="sum"/>
</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="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="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="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="pr">
<long name="count">100</long>
<null name="mc"/>
<null name="mean"/>
<null name="su"/>
<null name="sum"/>
<null name="unique"/>
</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="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 name="nr">
<double name="c">-100.0</double>
<long name="count">100</long>
<null name="s"/>
<null name="sum"/>
</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="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>
</response>
at __randomizedtesting.SeedInfo.seed([4AC03F1DF99E362A:2472881E118968FB]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.analytics.AbstractAnalyticsStatsTest.getStatResult(AbstractAnalyticsStatsTest.java:113)
at org.apache.solr.analytics.expression.ExpressionTest.powerTest(ExpressionTest.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)
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">7</int> </lst> <result name="response" numFound="100" start="0"> </result> <lst name="stats"> <lst name="stats_fields"/> </lst> <lst name="stats"> <lst name="avr"> <double name="c">100.0</double> <long name="count">100</long> <null name="s"/> <null name="sum"/> </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="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="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="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="pr"> <long name="count">100</long> <null name="mc"/> <null name="mean"/> <null name="su"/> <null name="sum"/> <null name="unique"/> </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="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 name="nr"> <double name="c">-100.0</double> <long name="count">100</long> <null name="s"/> <null name="sum"/> </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="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> </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">7</int>
</lst>
<result name="response" numFound="100" start="0">
</result>
<lst name="stats">
<lst name="stats_fields"/>
</lst>
<lst name="stats">
<lst name="avr">
<double name="c">100.0</double>
<long name="count">100</long>
<null name="s"/>
<null name="sum"/>
</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="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="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="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="pr">
<long name="count">100</long>
<null name="mc"/>
<null name="mean"/>
<null name="su"/>
<null name="sum"/>
<null name="unique"/>
</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="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 name="nr">
<double name="c">-100.0</double>
<long name="count">100</long>
<null name="s"/>
<null name="sum"/>
</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="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>
</response>
at __randomizedtesting.SeedInfo.seed([4AC03F1DF99E362A:42C857B85DB3669A]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.analytics.AbstractAnalyticsStatsTest.getStatResult(AbstractAnalyticsStatsTest.java:113)
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.analytics.expression.ExpressionTest.absoluteValueTest
Error Message:
Caught exception in getStatResult, xPath = /response/lst[@name='stats']/lst[@name='avr']/double[@name='sum'] raw data: <?xml version="1.0" encoding="UTF-8"?> <response> <lst name="responseHeader"> <int name="status">0</int> <int name="QTime">7</int> </lst> <result name="response" numFound="100" start="0"> </result> <lst name="stats"> <lst name="stats_fields"/> </lst> <lst name="stats"> <lst name="avr"> <double name="c">100.0</double> <long name="count">100</long> <null name="s"/> <null name="sum"/> </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="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="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="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="pr"> <long name="count">100</long> <null name="mc"/> <null name="mean"/> <null name="su"/> <null name="sum"/> <null name="unique"/> </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="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 name="nr"> <double name="c">-100.0</double> <long name="count">100</long> <null name="s"/> <null name="sum"/> </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="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> </response>
Stack Trace:
java.lang.AssertionError: Caught exception in getStatResult, xPath = /response/lst[@name='stats']/lst[@name='avr']/double[@name='sum']
raw data: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader">
<int name="status">0</int>
<int name="QTime">7</int>
</lst>
<result name="response" numFound="100" start="0">
</result>
<lst name="stats">
<lst name="stats_fields"/>
</lst>
<lst name="stats">
<lst name="avr">
<double name="c">100.0</double>
<long name="count">100</long>
<null name="s"/>
<null name="sum"/>
</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="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="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="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="pr">
<long name="count">100</long>
<null name="mc"/>
<null name="mean"/>
<null name="su"/>
<null name="sum"/>
<null name="unique"/>
</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="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 name="nr">
<double name="c">-100.0</double>
<long name="count">100</long>
<null name="s"/>
<null name="sum"/>
</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="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>
</response>
at __randomizedtesting.SeedInfo.seed([4AC03F1DF99E362A:6B6C1F0834036E4C]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.analytics.AbstractAnalyticsStatsTest.getStatResult(AbstractAnalyticsStatsTest.java:113)
at org.apache.solr.analytics.expression.ExpressionTest.absoluteValueTest(ExpressionTest.java:143)
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.handler.TestReplicationHandler.doTestStressReplication
Error Message:
timed out waiting for collection1 startAt time to exceed: Wed Dec 04 06:57:20 IST 2013
Stack Trace:
java.lang.AssertionError: timed out waiting for collection1 startAt time to exceed: Wed Dec 04 06:57:20 IST 2013
at __randomizedtesting.SeedInfo.seed([4AC03F1DF99E362A:916B3FDBFCB65F99]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.handler.TestReplicationHandler.watchCoreStartAt(TestReplicationHandler.java:1515)
at org.apache.solr.handler.TestReplicationHandler.doTestStressReplication(TestReplicationHandler.java:819)
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:<2>
Stack Trace:
java.lang.AssertionError: expected:<1> but was:<2>
at __randomizedtesting.SeedInfo.seed([4AC03F1DF99E362A:11F0C4D5FAD99556]: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 10007 lines...]
[junit4] Suite: org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest
[junit4] 2> 64007 T291 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1386120057243
[junit4] 2> 64008 T291 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> 64009 T291 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> 64009 T291 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> 64070 T291 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 64140 T291 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 64141 T291 oass.IndexSchema.readSchema Reading Solr Schema from schema12.xml
[junit4] 2> 64151 T291 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 64562 T291 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 64564 T291 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 64566 T291 oass.IndexSchema.readSchema WARN Field text is not multivalued and destination for multiple copyFields (2)
[junit4] 2> 64574 T291 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 64577 T291 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 64581 T291 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 64581 T291 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> 64582 T291 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/'
[junit4] 2> 64589 T291 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 64589 T291 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> 64589 T291 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/'
[junit4] 2> 64628 T291 oasc.CoreContainer.<init> New CoreContainer 1530945760
[junit4] 2> 64628 T291 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> 64630 T291 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 64630 T291 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 64631 T291 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 64631 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 64632 T291 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 64632 T291 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 64633 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 64633 T291 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 64634 T291 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 64640 T291 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 64640 T291 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 64641 T291 oasc.CoreContainer.load Host Name:
[junit4] 2> 64645 T292 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> 64646 T292 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> 64647 T292 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> 64647 T292 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> 64699 T292 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 64767 T292 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 64768 T292 oass.IndexSchema.readSchema Reading Solr Schema from schema12.xml
[junit4] 2> 64778 T292 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 65118 T292 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 65120 T292 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 65122 T292 oass.IndexSchema.readSchema WARN Field text is not multivalued and destination for multiple copyFields (2)
[junit4] 2> 65131 T292 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 65134 T292 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 65139 T292 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 65139 T292 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-1386120057243/
[junit4] 2> 65140 T292 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7fb1b1b6
[junit4] 2> 65140 T292 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1386120057243
[junit4] 2> 65141 T292 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-1386120057243/index/
[junit4] 2> 65141 T292 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1386120057243/index' doesn't exist. Creating new index...
[junit4] 2> 65141 T292 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-SignatureUpdateProcessorFactoryTest-1386120057243/index
[junit4] 2> 65142 T292 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=30, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 65143 T292 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_1,generation=1}
[junit4] 2> 65143 T292 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 65144 T292 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4] 2> 65147 T292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 65148 T292 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 65148 T292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 65149 T292 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 65149 T292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 65150 T292 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 65150 T292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 65151 T292 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 65151 T292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 65152 T292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 65152 T292 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 65153 T292 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 65153 T292 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 65154 T292 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 65154 T292 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 65155 T292 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 65155 T292 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4] 2> 65156 T292 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4] 2> 65159 T292 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 65159 T292 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 65160 T292 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 65161 T292 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 65161 T292 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 65161 T292 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 65162 T292 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 65163 T292 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 65163 T292 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 65164 T292 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 65165 T292 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 65166 T292 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 65167 T292 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 65167 T292 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 65168 T292 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 65169 T292 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4] 2> 65169 T292 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 65171 T292 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 65173 T292 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 65179 T292 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 65179 T292 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 65184 T292 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=26, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.856003706375346]
[junit4] 2> 65190 T292 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_1,generation=1}
[junit4] 2> 65191 T292 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 65191 T292 oass.SolrIndexSearcher.<init> Opening Searcher@eb549d5f main
[junit4] 2> 65192 T292 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 65229 T292 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 65278 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@eb549d5f main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 65291 T292 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 65296 T291 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 65301 T291 oas.SolrTestCaseJ4.setUp ###Starting testNonStringFieldsValues
[junit4] 2> ASYNC NEW_CORE C76 name=collection1 org.apache.solr.core.SolrCore@10b5fe8c
[junit4] 2> 65314 T291 C76 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 65316 T291 C76 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 6
[junit4] 2> 65328 T291 C76 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 65329 T291 C76 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_2,generation=2}
[junit4] 2> 65330 T291 C76 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 65331 T291 C76 oass.SolrIndexSearcher.<init> Opening Searcher@68a3e0fb main
[junit4] 2> 65336 T291 C76 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 65336 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@68a3e0fb main{StandardDirectoryReader(segments_2:2:nrt)}
[junit4] 2> 65338 T291 C76 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 10
[junit4] 2> 65346 T291 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 66418 T291 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 66429 T291 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_3,generation=3}
[junit4] 2> 66430 T291 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 66439 T291 oass.SolrIndexSearcher.<init> Opening Searcher@f6d04ef3 main
[junit4] 2> 66442 T291 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 66443 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f6d04ef3 main{StandardDirectoryReader(segments_3:4:nrt _0(5.0):c5/1:delGen=1)}
[junit4] 2> 66444 T291 oas.SolrTestCaseJ4.tearDown ###Ending testNonStringFieldsValues
[junit4] 2> 66451 T291 oas.SolrTestCaseJ4.setUp ###Starting testFailNonIndexedSigWithOverwriteDupes
[junit4] 2> ASYNC NEW_CORE C77 name=collection1 org.apache.solr.core.SolrCore@10b5fe8c
[junit4] 2> 66468 T291 C77 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 66469 T291 C77 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4] 2> 66745 T291 C77 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 66746 T291 C77 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_4,generation=4}
[junit4] 2> 66746 T291 C77 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 66747 T291 C77 oass.SolrIndexSearcher.<init> Opening Searcher@ba3d667b main
[junit4] 2> 66748 T291 C77 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 66750 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ba3d667b main{StandardDirectoryReader(segments_4:5:nrt)}
[junit4] 2> 66751 T291 C77 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 6
[junit4] 2> 66753 T291 oas.SolrTestCaseJ4.tearDown ###Ending testFailNonIndexedSigWithOverwriteDupes
[junit4] 2> 66760 T291 oas.SolrTestCaseJ4.setUp ###Starting testDupeAllFieldsDetection
[junit4] 2> 66769 T291 C77 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 66770 T291 C77 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 1
[junit4] 2> 66787 T291 C77 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 66794 T291 C77 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_5,generation=5}
[junit4] 2> 66795 T291 C77 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 66796 T291 C77 oass.SolrIndexSearcher.<init> Opening Searcher@978c0ded main
[junit4] 2> 66799 T291 C77 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 66802 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@978c0ded main{StandardDirectoryReader(segments_5:6:nrt)}
[junit4] 2> 66803 T291 C77 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 20
[junit4] 2> 66815 T291 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 66820 T291 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_5,generation=5}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_6,generation=6}
[junit4] 2> 66821 T291 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
[junit4] 2> 66823 T291 oass.SolrIndexSearcher.<init> Opening Searcher@25f30cc9 main
[junit4] 2> 66824 T291 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 66826 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@25f30cc9 main{StandardDirectoryReader(segments_6:8:nrt _1(5.0):c3)}
[junit4] 2> 66827 T291 oas.SolrTestCaseJ4.tearDown ###Ending testDupeAllFieldsDetection
[junit4] 2> 66834 T291 oas.SolrTestCaseJ4.setUp ###Starting testMultiThreaded
[junit4] 2> 66843 T291 C77 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 66844 T291 C77 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:*} 0 2
[junit4] 2> 66854 T291 C77 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 66855 T291 C77 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_6,generation=6}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_7,generation=7}
[junit4] 2> 66856 T291 C77 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 7
[junit4] 2> 66857 T291 C77 oass.SolrIndexSearcher.<init> Opening Searcher@1d4c9208 main
[junit4] 2> 66858 T291 C77 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 66860 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1d4c9208 main{StandardDirectoryReader(segments_7:9:nrt)}
[junit4] 2> 66861 T291 C77 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 7
[junit4] 2> 66892 T303 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 66992 T303 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_7,generation=7}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_8,generation=8}
[junit4] 2> 66993 T303 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 8
[junit4] 2> 67140 T303 oass.SolrIndexSearcher.<init> Opening Searcher@a2a0da63 main
[junit4] 2> 67145 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@a2a0da63 main{StandardDirectoryReader(segments_8:32:nrt _7(5.0):c47/46:delGen=1 _9(5.0):c7/6:delGen=1)}
[junit4] 2> 67145 T303 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 67146 T302 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 67255 T302 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_8,generation=8}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_9,generation=9}
[junit4] 2> 67255 T302 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 9
[junit4] 2> 67280 T302 oass.SolrIndexSearcher.<init> Opening Searcher@cfdcbd23 main
[junit4] 2> 67286 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@cfdcbd23 main{StandardDirectoryReader(segments_9:44:nrt _f(5.0):c14/12:delGen=1)}
[junit4] 2> 67287 T302 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 67288 T304 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 67289 T304 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_9,generation=9}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_a,generation=10}
[junit4] 2> 67289 T304 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 10
[junit4] 2> 67290 T304 oass.SolrIndexSearcher.<init> Opening Searcher@876107af main
[junit4] 2> 67291 T304 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 67291 T303 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 67293 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@876107af main{StandardDirectoryReader(segments_9:44:nrt _f(5.0):c14/12:delGen=1)}
[junit4] 2> 67302 T303 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_a,generation=10}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_b,generation=11}
[junit4] 2> 67303 T303 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 11
[junit4] 2> 67313 T303 oass.SolrIndexSearcher.<init> Opening Searcher@805e749d main
[junit4] 2> 67319 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@805e749d main{StandardDirectoryReader(segments_b:51:nrt _h(5.0):c1)}
[junit4] 2> 67320 T303 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 67320 T304 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 67323 T304 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_b,generation=11}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_c,generation=12}
[junit4] 2> 67323 T304 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 12
[junit4] 2> 67332 T304 oass.SolrIndexSearcher.<init> Opening Searcher@c44509b8 main
[junit4] 2> 67333 T304 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 67333 T302 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 67334 T302 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_c,generation=12}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_d,generation=13}
[junit4] 2> 67335 T302 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 13
[junit4] 2> 67335 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c44509b8 main{StandardDirectoryReader(segments_c:55:nrt _i(5.0):c1)}
[junit4] 2> 67336 T302 oass.SolrIndexSearcher.<init> Opening Searcher@831470e9 main
[junit4] 2> 67336 T302 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 67337 T303 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 67337 T303 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 67339 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@831470e9 main{StandardDirectoryReader(segments_c:55:nrt _i(5.0):c1)}
[junit4] 2> 67346 T303 oass.SolrIndexSearcher.<init> Opening Searcher@f38d816c main
[junit4] 2> 67347 T303 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 67347 T304 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 67348 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f38d816c main{StandardDirectoryReader(segments_d:60:nrt _j(5.0):c1)}
[junit4] 2> 67359 T304 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_d,generation=13}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_e,generation=14}
[junit4] 2> 67360 T304 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 14
[junit4] 2> 67366 T304 oass.SolrIndexSearcher.<init> Opening Searcher@dd1eb89 main
[junit4] 2> 67367 T304 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 67368 T302 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 67369 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@dd1eb89 main{StandardDirectoryReader(segments_e:65:nrt _k(5.0):c1 _l(5.0):c1)}
[junit4] 2> 67369 T302 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_e,generation=14}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_f,generation=15}
[junit4] 2> 67370 T302 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 15
[junit4] 2> 67371 T302 oass.SolrIndexSearcher.<init> Opening Searcher@f7c85b24 main
[junit4] 2> 67371 T302 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 67372 T303 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 67372 T303 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 67373 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f7c85b24 main{StandardDirectoryReader(segments_e:65:nrt _k(5.0):c1 _l(5.0):c1)}
[junit4] 2> 67373 T303 oass.SolrIndexSearcher.<init> Opening Searcher@1524f947 main
[junit4] 2> 67374 T303 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 67376 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1524f947 main{StandardDirectoryReader(segments_e:65:nrt _k(5.0):c1 _l(5.0):c1)}
[junit4] 2> 67379 T302 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 67390 T302 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_f,generation=15}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_g,generation=16}
[junit4] 2> 67390 T302 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 16
[junit4] 2> 67396 T302 oass.SolrIndexSearcher.<init> Opening Searcher@ba06d9f3 main
[junit4] 2> 67397 T302 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 67397 T304 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 67398 T304 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_g,generation=16}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_h,generation=17}
[junit4] 2> 67399 T304 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 17
[junit4] 2> 67399 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ba06d9f3 main{StandardDirectoryReader(segments_g:73:nrt _m(5.0):c1 _o(5.0):c1)}
[junit4] 2> 67400 T304 oass.SolrIndexSearcher.<init> Opening Searcher@8ad7d6f7 main
[junit4] 2> 67400 T304 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 67401 T303 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 67401 T303 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 67402 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@8ad7d6f7 main{StandardDirectoryReader(segments_g:73:nrt _m(5.0):c1 _o(5.0):c1)}
[junit4] 2> 67413 T303 oass.SolrIndexSearcher.<init> Opening Searcher@47724849 main
[junit4] 2> 67414 T303 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 67414 T304 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 67416 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@47724849 main{StandardDirectoryReader(segments_h:78:nrt _m(5.0):c1 _p(5.0):c1)}
[junit4] 2> 67420 T304 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_h,generation=17}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb6ea27c)),segFN=segments_i,generation=18}
[junit4] 2> 67421 T304 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 18
[junit4] 2> 67421 T304 oass.SolrIndexSearcher.<init> Opening Searcher@4b0d28ff main
[junit4] 2> 67422 T304 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 67423 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4b0d28ff main{StandardDirectoryReader(segments_i:81:nrt)}
[junit4] 2> 67424 T302 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 67431 T302 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9cc81272 lockFactor
[...truncated too long message...]
ouble>
[junit4] > <double name="c8">8.0</double>
[junit4] > </lst>
[junit4] > <lst name="dr">
[junit4] > <long name="count">100</long>
[junit4] > <double name="mc">0.2891</double>
[junit4] > <double name="mean">28.91</double>
[junit4] > <double name="su">80.30555555555556</double>
[junit4] > <double name="sum">2891.0</double>
[junit4] > <long name="unique">36</long>
[junit4] > </lst>
[junit4] > </lst>
[junit4] > </response>
[junit4] > at __randomizedtesting.SeedInfo.seed([4AC03F1DF99E362A:6B6C1F0834036E4C]:0)
[junit4] > at org.apache.solr.analytics.AbstractAnalyticsStatsTest.getStatResult(AbstractAnalyticsStatsTest.java:113)
[junit4] > at org.apache.solr.analytics.expression.ExpressionTest.absoluteValueTest(ExpressionTest.java:143)
[junit4] > at java.lang.Thread.run(Thread.java:780)
[junit4] 2> 692053 T1758 oas.SolrTestCaseJ4.setUp ###Starting constantDateTest
[junit4] 2> 692056 T1758 oas.SolrTestCaseJ4.tearDown ###Ending constantDateTest
[junit4] 2> 692060 T1758 oas.SolrTestCaseJ4.setUp ###Starting reverseTest
[junit4] 2> 692063 T1758 oas.SolrTestCaseJ4.tearDown ###Ending reverseTest
[junit4] 2> 692067 T1758 oas.SolrTestCaseJ4.setUp ###Starting divideTest
[junit4] 2> 692071 T1758 oas.SolrTestCaseJ4.tearDown ###Ending divideTest
[junit4] 2> 692073 T1758 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 692073 T1758 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=-22377428
[junit4] 2> 692074 T1758 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@70a3f9f6
[junit4] 2> 692074 T1758 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,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> 692074 T1758 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 692075 T1758 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 692075 T1758 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 692075 T1758 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 692076 T1758 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 692076 T1758 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-ExpressionTest-1386120684464 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-ExpressionTest-1386120684464;done=false>>]
[junit4] 2> 692076 T1758 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-ExpressionTest-1386120684464
[junit4] 2> 692077 T1758 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-ExpressionTest-1386120684464/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-ExpressionTest-1386120684464/index;done=false>>]
[junit4] 2> 692077 T1758 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-ExpressionTest-1386120684464/index
[junit4] 2> NOTE: test params are: codec=Lucene46: {int_id=PostingsFormat(name=Lucene41WithOrds), double_dd=PostingsFormat(name=MockRandom), string_sd=PostingsFormat(name=Lucene41WithOrds), float_fd=PostingsFormat(name=Memory doPackFST= false), long_ld=PostingsFormat(name=Lucene41WithOrds), id=PostingsFormat(name=Lucene41WithOrds), date_dtd=PostingsFormat(name=Lucene41WithOrds)}, docValues:{float_fd=DocValuesFormat(name=Disk), datedv=DocValuesFormat(name=Lucene45), double_dd=DocValuesFormat(name=Lucene45), stringdvm=DocValuesFormat(name=SimpleText), longdv=DocValuesFormat(name=SimpleText), stringdv=DocValuesFormat(name=Memory), floatdv=DocValuesFormat(name=SimpleText), date_dtd=DocValuesFormat(name=Memory), string_sd=DocValuesFormat(name=Memory), long_ld=DocValuesFormat(name=Memory), intdv=DocValuesFormat(name=Disk), doubledv=DocValuesFormat(name=Memory), int_id=DocValuesFormat(name=Memory)}, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=sk, timezone=America/Atikokan
[junit4] 2> NOTE: Linux 3.8.0-34-generic amd64/IBM Corporation 1.7.0 (64-bit)/cpus=8,threads=1,free=61316448,total=214433792
[junit4] 2> NOTE: All tests run in this JVM: [SuggesterWFSTTest, TestManagedSchema, TestFastWriter, ParsingFieldUpdateProcessorsTest, SolrXmlInZkTest, HdfsLockFactoryTest, TestQueryTypes, TestComponentsName, AbstractAnalyticsFacetTest, TestBinaryResponseWriter, TestReload, PluginInfoTest, TestSolrCoreProperties, TermVectorComponentDistributedTest, TestRTGBase, SimplePostToolTest, SignatureUpdateProcessorFactoryTest, TestSolrXml, StandardRequestHandlerTest, TestDocBasedVersionConstraints, HighlighterConfigTest, DirectSolrConnectionTest, DisMaxRequestHandlerTest, TestQuerySenderNoQuery, TestCSVLoader, SolrCoreCheckLockOnStartupTest, TestOmitPositions, DistanceFunctionTest, TestDistributedSearch, TestIndexSearcher, MultiTermTest, TestDFRSimilarityFactory, HardAutoCommitTest, CoreMergeIndexesAdminHandlerTest, DistributedSuggesterComponentTest, BasicDistributedZk2Test, TestHighFrequencyDictionaryFactory, TestDynamicFieldCollectionResource, TestSolrQueryParserResource, TestFieldResource, HdfsCollectionsAPIDistributedZkTest, TestSolrXmlPersistence, TestIBSimilarityFactory, SolrIndexConfigTest, TestUniqueKeyFieldResource, TestFieldTypeCollectionResource, TestLazyCores, ZkNodePropsTest, TestRandomMergePolicy, ChaosMonkeyNothingIsSafeTest, DirectUpdateHandlerTest, TestRecovery, TestXIncludeConfig, XmlUpdateRequestHandlerTest, TestDynamicFieldResource, HdfsBasicDistributedZk2Test, ZkSolrClientTest, FileUtilsTest, TestSchemaSimilarityResource, TestFastLRUCache, TestJmxIntegration, TestDefaultSimilarityFactory, NoCacheHeaderTest, FieldFacetTest, RequestHandlersTest, HighlighterTest, DirectSolrSpellCheckerTest, DateFieldTest, TestIndexingPerformance, TestAnalyzeInfixSuggestions, DistributedQueryComponentCustomSortTest, TestBinaryField, TestStressLucene, OpenExchangeRatesOrgProviderTest, AlternateDirectoryTest, TestStressRecovery, TestRangeQuery, TestFiltering, HdfsChaosMonkeySafeLeaderTest, PingRequestHandlerTest, TestFuzzyAnalyzedSuggestions, BasicZkTest, OpenCloseCoreStressTest, SortByFunctionTest, TestAnalyzedSuggestions, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest, SyncSliceTest, LeaderElectionIntegrationTest, RecoveryZkTest, FullSolrCloudDistribCmdsTest, ClusterStateUpdateTest, TestRandomFaceting, TestMultiCoreConfBootstrap, TestStressVersions, TestSolr4Spatial, SolrCmdDistributorTest, PeerSyncTest, BadIndexSchemaTest, ConvertedLegacyTest, TestBadConfig, OverseerCollectionProcessorTest, CurrencyFieldOpenExchangeTest, DistributedQueryElevationComponentTest, CurrencyFieldXmlFileTest, TestExtendedDismaxParser, CoreAdminHandlerTest, TestFoldingMultitermQuery, DocValuesTest, SuggesterTSTTest, WordBreakSolrSpellCheckerTest, TestPseudoReturnFields, FieldMutatingUpdateProcessorTest, TestWordDelimiterFilterFactory, DefaultValueUpdateProcessorTest, TestRemoteStreaming, DocValuesMultiTest, XsltUpdateRequestHandlerTest, LukeRequestHandlerTest, TermsComponentTest, DocumentBuilderTest, RequiredFieldsTest, TestSolrQueryParser, FastVectorHighlighterTest, LoggingHandlerTest, IndexSchemaTest, JSONWriterTest, QueryParsingTest, UniqFieldsUpdateProcessorFactoryTest, CoreContainerCoreInitFailuresTest, TestLFUCache, TestQuerySenderListener, CopyFieldTest, TestSolrDeletionPolicy2, MinimalSchemaTest, TestPostingsSolrHighlighter, TestCharFilters, SynonymTokenizerTest, TestPerFieldSimilarity, TestLMDirichletSimilarityFactory, TimeZoneUtilsTest, DateMathParserTest, PreAnalyzedFieldTest, TestSolrJ, TestUtils, SliceStateTest, AbstractAnalyticsStatsTest, ExpressionTest]
[junit4] Completed on J1 in 0.88s, 12 tests, 4 failures <<< FAILURES!
[...truncated 141 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:420: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:413: 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:1304: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:937: There were test failures: 357 suites, 1571 tests, 6 failures, 68 ignored (6 assumptions)
Total time: 36 minutes 47 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 (64bit/jdk1.7.0_45) - Build #
8563 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/8563/
Java: 64bit/jdk1.7.0_45 -XX:+UseCompressedOops -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
Stack Trace:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at __randomizedtesting.SeedInfo.seed([5E95D6426C8393DE:5A9D59B17E267CFF]:0)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:424)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:421)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:378)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:365)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:102)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:157)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:153)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:584)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
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:744)
Build Log:
[...truncated 10304 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> 559365 T2708 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-OverseerTest-1386125769068
[junit4] 2> 559366 T2708 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 559371 T2708 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 559372 T2708 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 559373 T2709 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 559473 T2708 oasc.ZkTestServer.run start zk server on port:43215
[junit4] 2> 559474 T2708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 559498 T2715 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b3ef039 name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 559498 T2708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 559499 T2708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 559502 T2717 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@492a538c name:ZooKeeperConnection Watcher:127.0.0.1:43215 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 559503 T2708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 559507 T2708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 559509 T2719 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@73020324 name:ZooKeeperConnection Watcher:127.0.0.1:43215 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 559509 T2708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 559509 T2708 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 559514 T2708 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 559519 T2720 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 559520 T2708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 559522 T2722 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@166406cf name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 559522 T2720 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 559523 T2724 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d5ad09e name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 559523 T2708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 559523 T2720 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 559524 T2708 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 559528 T2708 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 559530 T2720 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 559531 T2708 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 559534 T2720 oasc.Overseer.start Overseer (id=90841138402295811-127.0.0.1:43215_solr-n_0000000000) starting
[junit4] 2> 559535 T2708 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 559537 T2720 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 559539 T2724 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 559542 T2720 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 559547 T2720 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 559550 T2720 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 559551 T2726 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 559553 T2720 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 559555 T2728 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e5de96a name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 559555 T2720 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 559560 T2720 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 559563 T2720 oasc.Overseer.start Overseer (id=90841138402295813-127.0.0.1:43215_solr-n_0000000001) starting
[junit4] 2> 559569 T2730 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 559570 T2729 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 559573 T2729 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 559574 T2729 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 559574 T2729 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 559574 T2729 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 559577 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 559578 T2724 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> 560042 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 560050 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 560053 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560055 T2729 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 560056 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560056 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 560059 T2729 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 560059 T2729 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 560062 T2708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 560062 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560064 T2732 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d7a959d name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 560064 T2708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 560066 T2708 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 560069 T2708 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 560074 T2724 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 560074 T2732 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 560077 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560077 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 560079 T2729 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 560079 T2729 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 560083 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560086 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 560188 T2732 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> 560188 T2724 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> 560289 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 560294 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560294 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560294 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560296 T2729 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 560298 T2729 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 560298 T2729 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 560298 T2729 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 560303 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560406 T2724 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> 560406 T2732 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> 560794 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 560805 T2724 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 560806 T2732 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 560807 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 560808 T2732 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 560814 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560815 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560815 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560817 T2729 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 560823 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 560926 T2732 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> 561009 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 561012 T2708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 561014 T2734 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b8ae262 name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 561014 T2708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 561016 T2708 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 561021 T2708 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 561024 T2734 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 561024 T2732 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 561027 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561028 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561028 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561027 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 561031 T2729 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 561032 T2729 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 561032 T2729 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 561036 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561039 T2734 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 561040 T2732 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 561042 T2734 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 561043 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561044 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 561045 T2729 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 561045 T2729 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 561049 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561050 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561051 T2725 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer work queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue-work
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:252)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:89)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.element(DistributedQueue.java:131)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:325)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:103)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 561051 T2726 oasc.OverseerCollectionProcessor.amILeader org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:269)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:203)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:155)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 561053 T2726 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=90841138402295811-127.0.0.1:43215_solr-n_0000000000) am no longer a leader.
[junit4] 2> 561054 T2726 oasc.OverseerCollectionProcessor.amILeader org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:269)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:203)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:162)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 561054 T2726 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=90841138402295811-127.0.0.1:43215_solr-n_0000000000) am no longer a leader.
[junit4] 2> 561053 T2708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 561055 T2736 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4efe4dd8 name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 561055 T2708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 561056 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561057 T2708 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 561062 T2708 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 561067 T2734 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 561068 T2736 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 561071 T2728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561071 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 561071 T2720 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 561073 T2729 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 561073 T2729 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 561075 T2720 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 561077 T2738 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@599b4c81 name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 561077 T2720 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 561080 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 561081 T2720 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 561084 T2720 oasc.Overseer.start Overseer (id=90841138402295817-127.0.0.1:43215_solr-n_0000000002) starting
[junit4] 2> 561089 T2740 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 561092 T2739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 561093 T2739 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 561094 T2739 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 561094 T2739 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 561095 T2736 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> 561095 T2734 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> 561100 T2739 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 561100 T2739 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 561101 T2734 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> 561102 T2736 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> 561108 T2736 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> 561109 T2734 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> 561112 T2739 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 561116 T2739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 561117 T2739 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 561117 T2739 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 561121 T2738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561123 T2734 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> 561123 T2736 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> 561282 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 561287 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 561287 T2738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561290 T2739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 561291 T2739 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 561291 T2739 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 561295 T2738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561296 T2736 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 561296 T2734 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 561298 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 561298 T2736 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 561305 T2738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561310 T2738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561413 T2736 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> 561500 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 561502 T2708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 561504 T2742 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@27f8971b name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 561505 T2708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 561507 T2708 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 561511 T2708 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 561515 T2736 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 561515 T2742 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 561518 T2738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561518 T2738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561518 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 561518 T2738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561521 T2739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 561522 T2739 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 561522 T2739 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 561526 T2738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561528 T2736 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 561528 T2742 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 561531 T2742 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 561532 T2738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561532 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 561533 T2739 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 561534 T2739 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 561537 T2738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561540 T2708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 561542 T2738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561542 T2744 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@21cf0884 name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 561543 T2708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 561544 T2708 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 561547 T2708 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 561551 T2742 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 561552 T2744 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 561554 T2738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561554 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 561556 T2739 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 561556 T2739 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 561560 T2738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561562 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 561590 T2720 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 561593 T2720 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 561594 T2746 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@44cff9d7 name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 561595 T2720 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 561599 T2720 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 561602 T2720 oasc.Overseer.start Overseer (id=90841138402295820-127.0.0.1:43215_solr-n_0000000003) starting
[junit4] 2> 561610 T2748 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 561613 T2747 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 561614 T2747 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 561615 T2747 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 561616 T2747 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 561617 T2744 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> 561617 T2742 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> 561622 T2747 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 561622 T2747 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 561624 T2742 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> 561624 T2744 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> 561631 T2742 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> 561631 T2744 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> 561635 T2747 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 561635 T2747 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 561637 T2744 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> 561637 T2742 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> 561640 T2747 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 561661 T2739 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:252)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:89)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:411)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:193)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 561765 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 561769 T2746 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561770 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 561772 T2747 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 561773 T2747 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 561774 T2747 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 561778 T2746 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561779 T2742 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> 561779 T2744 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> 561782 T2744 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 561782 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 561784 T2744 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 561791 T2746 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561794 T2747 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 561799 T2746 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 561902 T2744 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> 561985 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 561987 T2708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 561989 T2750 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@61e62a34 name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 561990 T2708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 561992 T2708 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 561997 T2708 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 562001 T2744 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 562001 T2750 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 562004 T2746 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562004 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 562004 T2746 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562005 T2746 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562007 T2747 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562008 T2747 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 562008 T2747 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 562011 T2720 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 562013 T2720 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 562015 T2752 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4fe7d389 name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 562015 T2720 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 562016 T2750 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 562016 T2744 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 562020 T2750 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 562020 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 562021 T2720 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 562024 T2720 oasc.Overseer.start Overseer (id=90841138402295822-127.0.0.1:43215_solr-n_0000000004) starting
[junit4] 2> 562032 T2708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 562035 T2754 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@129509d6 name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 562035 T2708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 562035 T2756 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 562037 T2708 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 562038 T2755 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562039 T2755 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 562040 T2755 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 562040 T2755 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 562041 T2708 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 562042 T2750 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> 562042 T2754 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> 562045 T2754 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 562045 T2750 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 562045 T2755 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 562048 T2752 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562048 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 562048 T2755 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562049 T2755 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 562050 T2755 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 562054 T2750 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> 562054 T2754 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> 562056 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562059 T2755 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562060 T2755 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 562061 T2755 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 562065 T2752 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562070 T2752 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562072 T2755 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 562072 T2755 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 562076 T2752 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562179 T2750 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> 562179 T2754 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> 562258 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562263 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 562263 T2752 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562264 T2752 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562264 T2752 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562267 T2755 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562268 T2755 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 562268 T2755 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 562272 T2752 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562273 T2750 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 562273 T2754 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 562274 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562275 T2754 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 562283 T2752 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562290 T2752 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562306 T2724 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:252)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 562307 T2724 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:252)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 562393 T2754 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> 562477 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562479 T2708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 562481 T2758 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2122a394 name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 562482 T2708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 562484 T2708 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 562488 T2708 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 562492 T2758 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 562492 T2754 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 562495 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 562495 T2752 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562496 T2752 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562496 T2752 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562498 T2755 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562499 T2755 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 562500 T2755 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 562504 T2752 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562505 T2758 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 562505 T2754 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 562507 T2758 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 562508 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 562508 T2752 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562510 T2755 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 562511 T2755 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 562514 T2752 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562517 T2708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 562519 T2760 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50af8c87 name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 562519 T2708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 562520 T2752 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562521 T2708 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 562524 T2708 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 562528 T2758 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 562528 T2760 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 562532 T2752 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562532 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 562534 T2755 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 562534 T2755 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 562536 T2720 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 562538 T2720 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 562540 T2762 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ed055ec name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 562540 T2720 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 562541 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562544 T2720 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 562547 T2720 oasc.Overseer.start Overseer (id=90841138402295826-127.0.0.1:43215_solr-n_0000000005) starting
[junit4] 2> 562552 T2764 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 562555 T2763 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562556 T2763 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 562557 T2763 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 562557 T2763 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 562558 T2760 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> 562558 T2758 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> 562563 T2763 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 562563 T2763 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 562565 T2760 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> 562565 T2758 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> 562572 T2758 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> 562572 T2760 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> 562574 T2729 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue-work/qn-
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:235)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:232)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:232)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.createData(DistributedQueue.java:284)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.offer(DistributedQueue.java:271)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:186)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 562577 T2763 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 562577 T2763 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 562579 T2758 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> 562579 T2760 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> 562582 T2763 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 562585 T2763 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562586 T2763 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 562586 T2763 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 562590 T2762 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562591 T2760 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> 562591 T2758 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> 562744 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562749 T2762 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562749 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 562752 T2763 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562753 T2763 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 562753 T2763 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 562757 T2762 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562759 T2760 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 562759 T2758 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 562761 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562761 T2760 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 562769 T2762 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562775 T2762 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562797 T2734 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:252)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 562798 T2734 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:252)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 562879 T2760 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> 562963 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562966 T2708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 562968 T2766 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71095b10 name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 562968 T2708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 562970 T2708 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 562975 T2708 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 562980 T2760 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 562980 T2766 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 562983 T2762 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562983 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 562983 T2762 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562984 T2762 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562986 T2763 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 562987 T2763 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 562988 T2763 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 562991 T2762 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 562993 T2766 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 562993 T2760 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 562998 T2766 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 563000 T2762 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 563000 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 563002 T2763 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 563002 T2763 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 563006 T2762 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 563009 T2708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 563011 T2768 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@580c1ef2 name:ZooKeeperConnection Watcher:127.0.0.1:43215/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 563012 T2708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 563012 T2762 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 563013 T2708 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 563017 T2708 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 563020 T2768 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 563021 T2766 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 563024 T2762 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 563024 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 563026 T2763 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 563026 T2763 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 563029 T2762 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 563031 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 563053 T2720 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 563056 T2720 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKee
[...truncated too long message...]
00000000) starting
[junit4] 2> 580245 T2708 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 580247 T2708 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 580248 T2708 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 580250 T3184 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 580251 T3183 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 580252 T3183 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 580252 T3183 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 580252 T3183 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 580252 T3183 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 580254 T3182 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 580254 T3180 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> 580254 T3174 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> 580751 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 580757 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 580761 T3182 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 580761 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 580762 T3183 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 580763 T3174 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 580763 T3180 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 580764 T2708 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 580764 T3182 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 580766 T3186 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4099573d name:ZooKeeperConnection Watcher:127.0.0.1:42926/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 580766 T2708 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 580767 T2708 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 580768 T2708 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 580770 T3174 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 580770 T3186 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 580771 T3182 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 580771 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 580772 T3183 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 580772 T3183 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 580773 T3182 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 580777 T2708 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 580781 T3182 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 580782 T3049 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 580784 T3182 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 580786 T3051 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 580885 T3174 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> 580885 T3186 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> 580887 T2708 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 580890 T3174 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 580893 T2708 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42926 42926
[junit4] 2> 580928 T2708 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 580930 T2708 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 580930 T2708 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 582390 T3186 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 583930 T2708 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=DefaultSimilarity, locale=et, timezone=Asia/Krasnoyarsk
[junit4] 2> NOTE: Linux 3.8.0-34-generic amd64/Oracle Corporation 1.7.0_45 (64-bit)/cpus=8,threads=1,free=152389160,total=279445504
[junit4] 2> NOTE: All tests run in this JVM: [BinaryUpdateRequestHandlerTest, SchemaVersionSpecificBehaviorTest, ZkCLITest, TestManagedSchema, DistributedSuggesterComponentTest, EnumFieldTest, CSVRequestHandlerTest, TestSolrXmlPersistor, AbstractAnalyticsFacetTest, ScriptEngineTest, CircularListTest, TestBM25SimilarityFactory, CustomCollectionTest, CoreAdminHandlerTest, TestSolrXmlPersistence, AssignTest, ShardSplitTest, SolrIndexSplitterTest, DOMUtilTest, TestReplicationHandler, SoftAutoCommitTest, CoreAdminCreateDiscoverTest, TestWriterPerf, TestClassNameShortening, TermsComponentTest, DateMathParserTest, TestHighFrequencyDictionaryFactory, TestPostingsSolrHighlighter, TriLevelCompositeIdRoutingTest, TestSolrIndexConfig, DocValuesTest, TestNoOpRegenerator, TestDynamicFieldCollectionResource, URLClassifyProcessorTest, PrimitiveFieldTypeTest, HdfsBasicDistributedZk2Test, AnalysisAfterCoreReloadTest, SuggesterFSTTest, FileBasedSpellCheckerTest, IndexSchemaTest, TestJmxMonitoredMap, AddSchemaFieldsUpdateProcessorFactoryTest, TestDocSet, ParsingFieldUpdateProcessorsTest, ZkControllerTest, SuggesterTest, TestShardHandlerFactory, BJQParserTest, SolrCoreTest, TestMergePolicyConfig, TestLRUCache, TestFunctionQuery, PreAnalyzedUpdateProcessorTest, InfoHandlerTest, TestLMDirichletSimilarityFactory, SearchHandlerTest, StatelessScriptUpdateProcessorFactoryTest, ClusterStateTest, TestReversedWildcardFilterFactory, HdfsLockFactoryTest, DistributedTermsComponentTest, TestElisionMultitermQuery, TestLMJelinekMercerSimilarityFactory, TestFaceting, TestPerFieldSimilarity, OverseerTest]
[junit4] Completed on J0 in 24.60s, 8 tests, 1 error <<< FAILURES!
[...truncated 665 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:420: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:400: 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:1304: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:937: There were test failures: 357 suites, 1571 tests, 1 error, 34 ignored (6 assumptions)
Total time: 45 minutes 3 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_45 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure