You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/05/14 18:16:41 UTC
[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 1539 -
Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/1539/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseG1GC
All tests passed
Build Log:
[...truncated 11292 lines...]
[junit4] JVM J0: stderr was not empty, see: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/temp/junit4-J0-20140514_153436_157.syserr
[junit4] >>> JVM J0: stderr (verbatim) ----
[junit4] java(295,0x14fa92000) malloc: *** error for object 0x14fe80e10: pointer being freed was not allocated
[junit4] *** set a breakpoint in malloc_error_break to debug
[junit4] <<< JVM J0: EOF ----
[...truncated 1 lines...]
[junit4] ERROR: JVM J0 ended with an exception, command line: /Library/Java/JavaVirtualMachines/jdk1.7.0_55.jdk/Contents/Home/jre/bin/java -XX:-UseCompressedOops -XX:+UseG1GC -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/heapdumps -Dtests.prefix=tests -Dtests.seed=CB6ED772E04227AA -Xmx512M -Dtests.iters= -Dtests.verbose=false -Dtests.infostream=false -Dtests.codec=random -Dtests.postingsformat=random -Dtests.docvaluesformat=random -Dtests.locale=random -Dtests.timezone=random -Dtests.directory=random -Dtests.linedocsfile=europarl.lines.txt.gz -Dtests.luceneMatchVersion=4.9 -Dtests.cleanthreads=perClass -Djava.util.logging.config.file=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/tools/junit4/logging.properties -Dtests.nightly=false -Dtests.weekly=false -Dtests.monster=false -Dtests.slow=true -Dtests.asserts.gracious=false -Dtests.multiplier=1 -DtempDir=. -Djava.io.tmpdir=. -Djunit4.tempDir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/temp -Dclover.db.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/clover/db -Djava.security.manager=org.apache.lucene.util.TestSecurityManager -Djava.security.policy=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/tools/junit4/tests.policy -Dlucene.version=4.9-SNAPSHOT -Djetty.testMode=1 -Djetty.insecurerandom=1 -Dsolr.directoryFactory=org.apache.solr.core.MockDirectoryFactory -Djava.awt.headless=true -Djdk.map.althashing.threshold=0 -Dtests.leaveTemporary=false -Dtests.filterstacks=true -Dtests.disableHdfs=true -classpath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/classes/test:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-test-framework/classes/java:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/test-framework/lib/junit4-ant-2.1.3.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/test-framework/classes/java:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/codecs/classes/java:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-solrj/classes/java:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/classes/java:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/analysis/common/lucene-analyzers-common-4.9-SNAPSHOT.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/analysis/kuromoji/lucene-analyzers-kuromoji-4.9-SNAPSHOT.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/analysis/phonetic/lucene-analyzers-phonetic-4.9-SNAPSHOT.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/codecs/lucene-codecs-4.9-SNAPSHOT.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/highlighter/lucene-highlighter-4.9-SNAPSHOT.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/memory/lucene-memory-4.9-SNAPSHOT.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/misc/lucene-misc-4.9-SNAPSHOT.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/spatial/lucene-spatial-4.9-SNAPSHOT.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/expressions/lucene-expressions-4.9-SNAPSHOT.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/suggest/lucene-suggest-4.9-SNAPSHOT.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/grouping/lucene-grouping-4.9-SNAPSHOT.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/queries/lucene-queries-4.9-SNAPSHOT.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/queryparser/lucene-queryparser-4.9-SNAPSHOT.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/join/lucene-join-4.9-SNAPSHOT.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/antlr-runtime-3.5.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/asm-4.1.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/asm-commons-4.1.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/commons-cli-1.2.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/commons-codec-1.9.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/commons-configuration-1.6.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/commons-fileupload-1.2.1.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/commons-lang-2.6.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/concurrentlinkedhashmap-lru-1.2.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/dom4j-1.6.1.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/guava-14.0.1.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/hadoop-annotations-2.2.0.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/hadoop-auth-2.2.0.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/hadoop-common-2.2.0.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/hadoop-hdfs-2.2.0.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/hppc-0.5.2.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/joda-time-2.2.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/log4j-1.2.16.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/org.restlet-2.1.1.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/org.restlet.ext.servlet-2.1.1.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/protobuf-java-2.5.0.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/slf4j-log4j12-1.7.6.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/spatial4j-0.4.1.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/commons-io-2.1.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/httpclient-4.3.1.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/httpcore-4.3.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/httpmime-4.3.1.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/noggit-0.5.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/slf4j-api-1.7.6.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/wstx-asl-3.2.7.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/zookeeper-3.4.6.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-continuation-8.1.10.v20130312.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-deploy-8.1.10.v20130312.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-http-8.1.10.v20130312.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-io-8.1.10.v20130312.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-jmx-8.1.10.v20130312.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-security-8.1.10.v20130312.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-server-8.1.10.v20130312.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-servlet-8.1.10.v20130312.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-util-8.1.10.v20130312.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-webapp-8.1.10.v20130312.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-xml-8.1.10.v20130312.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/servlet-api-3.0.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/example-DIH/solr/db/lib/derby-10.9.1.0.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/example/example-DIH/solr/db/lib/hsqldb-1.8.0.10.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/core/classes/java:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/test-framework/lib/junit-4.10.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/test-framework/lib/randomizedtesting-runner-2.1.3.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/test-lib/cglib-nodep-2.2.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/test-lib/commons-collections-3.2.1.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/test-lib/easymock-3.0.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/test-lib/hadoop-common-2.2.0-tests.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/test-lib/hadoop-hdfs-2.2.0-tests.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/test-lib/javax.servlet-api-3.0.1.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/test-lib/jcl-over-slf4j-1.7.6.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/test-lib/jersey-core-1.8.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/test-lib/jetty-6.1.26.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/test-lib/jetty-util-6.1.26.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/test-lib/objenesis-1.2.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/analysis/icu/lucene-analyzers-icu-4.9-SNAPSHOT.jar:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/contrib/solr-analysis-extras/classes/java:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/contrib/analysis-extras/lib/icu4j-52.1.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-launcher.jar:/Users/jenkins/.ant/lib/ivy-2.3.0.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-antlr.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-bcel.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-bsf.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-log4j.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-oro.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-regexp.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-resolver.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-xalan2.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-commons-logging.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-commons-net.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jai.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-javamail.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jdepend.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jmf.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jsch.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-junit.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-junit4.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-netrexx.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-swing.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-testutil.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_55.jdk/Contents/Home/lib/tools.jar:/Users/jenkins/.ivy2/cache/com.carrotsearch.randomizedtesting/junit4-ant/jars/junit4-ant-2.1.3.jar -ea:org.apache.lucene... -ea:org.apache.solr... com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe -flush -eventsfile /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/temp/junit4-J0-20140514_153436_157.events @/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/temp/junit4-J0-20140514_153436_157.suites
[junit4] ERROR: JVM J0 ended with an exception: Forked process returned with error code: 134. Very likely a JVM crash. Process output piped in logs above.
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.executeSlave(JUnit4.java:1461)
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.access$000(JUnit4.java:133)
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:948)
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:945)
[junit4] at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[junit4] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] at java.lang.Thread.run(Thread.java:745)
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:467: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:447: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:45: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:496: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1297: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:921: At least one slave process threw an exception, first: Forked process returned with error code: 134. Very likely a JVM crash. Process output piped in logs above.
Total time: 82 minutes 47 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 1540 -
Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/1540/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
Stack Trace:
org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
at __randomizedtesting.SeedInfo.seed([5B22EF2D7D852104:5F2A60DE6F20CE25]:0)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:136)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
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:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
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:65)
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:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
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:65)
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:360)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
... 48 more
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
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:432)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:128)
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
... 49 more
Build Log:
[...truncated 10747 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.OverseerTest-5B22EF2D7D852104-001/init-core-data-001
[junit4] 2> 455432 T1205 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
[junit4] 2> 455433 T1205 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 455433 T1205 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 455443 T1205 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 455444 T1205 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 455445 T1206 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 455548 T1205 oasc.ZkTestServer.run start zk server on port:53617
[junit4] 2> 455549 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 455557 T1212 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@60b24cc9 name:ZooKeeperConnection Watcher:127.0.0.1:53617/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 455558 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 455563 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 455570 T1214 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58f9e78a name:ZooKeeperConnection Watcher:127.0.0.1:53617 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 455571 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 455580 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 455584 T1216 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b58e1f7 name:ZooKeeperConnection Watcher:127.0.0.1:53617 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 455584 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 455585 T1205 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 455597 T1205 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 455607 T1205 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 455611 T1205 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 455620 T1205 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 455631 T1205 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 455645 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 455652 T1218 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b52d873 name:ZooKeeperConnection Watcher:127.0.0.1:53617/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 455652 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 455655 T1205 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 455663 T1205 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 455674 T1205 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53617_solr
[junit4] 2> 455674 T1205 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 455680 T1205 oasc.Overseer.start Overseer (id=91757605418369027-127.0.0.1:53617_solr-n_0000000000) starting
[junit4] 2> 455686 T1205 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 455699 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 455708 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 455717 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 455727 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 455742 T1220 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 455745 T1220 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:53617_solr
[junit4] 2> 455750 T1219 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 455751 T1219 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 455753 T1219 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 455756 T1212 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 455764 T1219 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core2",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 455770 T1212 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 455773 T1219 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 455784 T1219 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 455785 T1219 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core3",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 455794 T1218 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 455796 T1212 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 455854 T1205 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53617 53617
[junit4] 2> 455886 T1206 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53617 53617
[junit4] 2> 456091 T1205 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 2> 456092 T1219 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:53617_solr
[junit4] 2> 456093 T1221 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data 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:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 456099 T1205 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment
[junit4] 2> 456103 T1205 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 456110 T1222 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 456210 T1205 oasc.ZkTestServer.run start zk server on port:53622
[junit4] 2> 456212 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 456219 T1228 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@52443768 name:ZooKeeperConnection Watcher:127.0.0.1:53622 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 456220 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 456225 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 456228 T1230 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@23e348c2 name:ZooKeeperConnection Watcher:127.0.0.1:53622 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 456229 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 456229 T1205 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 456237 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 456241 T1232 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3295bae3 name:ZooKeeperConnection Watcher:127.0.0.1:53622/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 456241 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 456242 T1205 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 456247 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 456251 T1234 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@587859e name:ZooKeeperConnection Watcher:127.0.0.1:53622/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 456251 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 456257 T1205 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 456261 T1205 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 456274 T1205 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53622_solr
[junit4] 2> 456275 T1205 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 456283 T1205 oasc.Overseer.start Overseer (id=91757605462016003-127.0.0.1:53622_solr-n_0000000000) starting
[junit4] 2> 456289 T1205 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 456299 T1205 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 456307 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 456317 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 456325 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 456340 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 456362 T1236 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 456363 T1205 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 456364 T1236 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:53622_solr
[junit4] 2> 456365 T1235 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 456371 T1205 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 456376 T1205 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 456384 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 456387 T1238 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2bece32 name:ZooKeeperConnection Watcher:127.0.0.1:53622/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 456388 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 456391 T1205 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 456398 T1205 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 456405 T1238 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 456405 T1232 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 456410 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 456415 T1235 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 456417 T1235 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 456417 T1235 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 456417 T1235 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 456425 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 456427 T1238 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> 456427 T1232 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> 456913 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 456948 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 456963 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 456968 T1235 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 456968 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 456979 T1235 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 456979 T1235 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 456979 T1235 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 456986 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 457095 T1238 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> 457095 T1232 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> 457471 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 457494 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 457509 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 457509 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 457509 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 457513 T1235 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 457513 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 457523 T1235 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 457523 T1235 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 457524 T1235 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 457530 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 457635 T1232 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> 457636 T1238 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> 458014 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 458035 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 458049 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 458049 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 458049 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 458054 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 458055 T1235 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 458066 T1235 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node4",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 458066 T1235 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 458066 T1235 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 458074 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 458181 T1238 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> 458181 T1232 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> 458556 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 458579 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 458579 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 458580 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 458584 T1235 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 458586 T1235 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core5",
[junit4] 2> "core_node_name":"node5",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 458586 T1235 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 458586 T1235 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 458592 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 458698 T1238 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> 458699 T1232 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> 459080 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 459102 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 459102 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 459102 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 459107 T1235 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 459109 T1235 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core6",
[junit4] 2> "core_node_name":"node6",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 459109 T1235 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 459110 T1235 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 459116 T1234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 459223 T1232 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> 459223 T1238 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> 459604 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 459626 T1238 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 459631 T1205 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53622 53622
[junit4] 2> 459727 T1222 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53622 53622
[junit4] 2> 459972 T1205 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
[junit4] 2> 459972 T1235 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:53622_solr
[junit4] 2> 459979 T1239 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data 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:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 459992 T1205 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
[junit4] 2> 459993 T1205 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 459994 T1240 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 460095 T1205 oasc.ZkTestServer.run start zk server on port:53628
[junit4] 2> 460096 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 460103 T1246 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ae84854 name:ZooKeeperConnection Watcher:127.0.0.1:53628 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 460103 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 460108 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 460112 T1248 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@52f1c9dc name:ZooKeeperConnection Watcher:127.0.0.1:53628 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 460112 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 460112 T1205 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 460122 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 460125 T1250 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6421ae56 name:ZooKeeperConnection Watcher:127.0.0.1:53628/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 460126 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 460126 T1205 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 460131 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 460134 T1252 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2373cc89 name:ZooKeeperConnection Watcher:127.0.0.1:53628/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 460135 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 460137 T1205 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 460144 T1205 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 460155 T1205 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53628_solr
[junit4] 2> 460155 T1205 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 460160 T1205 oasc.Overseer.start Overseer (id=91757605716426755-127.0.0.1:53628_solr-n_0000000000) starting
[junit4] 2> 460165 T1205 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 460174 T1205 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 460183 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 460192 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 460200 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 460211 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 460226 T1254 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 460227 T1205 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 460228 T1254 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:53628_solr
[junit4] 2> 460229 T1253 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 460235 T1205 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 460239 T1205 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 460246 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 460250 T1256 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@68e518d4 name:ZooKeeperConnection Watcher:127.0.0.1:53628/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 460250 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 460253 T1205 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 460260 T1205 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 460268 T1250 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 460268 T1256 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 460274 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 460279 T1253 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 460280 T1253 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 460281 T1253 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 460281 T1253 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 460288 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 460290 T1250 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> 460290 T1256 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> 460777 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 460803 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 460818 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 460823 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 460823 T1253 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 460833 T1253 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 460834 T1253 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 460834 T1253 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 460840 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 460947 T1256 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> 460947 T1250 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> 461128 T1238 oasc.LeaderElector$ElectionWatcher.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:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 461129 T1238 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard3/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:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 461129 T1238 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/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:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 461324 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 461345 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 461361 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 461361 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 461361 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 461366 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 461366 T1253 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 461377 T1253 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 461377 T1253 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 461377 T1253 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 461384 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 461491 T1250 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> 461492 T1256 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> 461868 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 461887 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 461901 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 461901 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 461901 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 461905 T1253 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 461913 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 462022 T1256 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> 462022 T1250 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> 462066 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 462066 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 462067 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 462070 T1253 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 462071 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 462072 T1253 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core0",
[junit4] 2> "core_node_name":"node0",
[junit4] 2> "collection":"",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 462082 T1253 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
[junit4] 2> "operation":"deletecore",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core0",
[junit4] 2> "core_node_name":"node0",
[junit4] 2> "collection":""}
[junit4] 2> 462089 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 462092 T1253 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 462092 T1253 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
[junit4] 2> 462092 T1253 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 462100 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 462209 T1250 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> 462209 T1256 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> 462577 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
[junit4] 2> 462601 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
[junit4] 2> 462619 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 462619 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 462619 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 462623 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 462623 T1253 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 462635 T1253 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 462635 T1253 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 462635 T1253 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 462642 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 462749 T1250 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> 462749 T1256 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> 463125 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
[junit4] 2> 463146 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
[junit4] 2> 463160 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 463160 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 463160 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 463164 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 463165 T1253 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 463178 T1253 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 463178 T1253 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 463178 T1253 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 463184 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 463291 T1256 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> 463292 T1250 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> 463667 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
[junit4] 2> 463687 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
[junit4] 2> 463700 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 463700 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 463701 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 463704 T1253 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 463712 T1252 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 463818 T1256 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> 463818 T1250 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> 463860 T1256 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 463864 T1205 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53628 53628
[junit4] 2> 463882 T1240 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53628 53628
[junit4] 2> 464097 T1205 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
[junit4] 2> 464098 T1253 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:53628_solr
[junit4] 2> 464100 T1257 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data 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:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 464107 T1205 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
[junit4] 2> 464109 T1205 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 464110 T1258 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 464211 T1205 oasc.ZkTestServer.run start zk server on port:53634
[junit4] 2> 464213 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 464220 T1264 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3d82e11a name:ZooKeeperConnection Watcher:127.0.0.1:53634/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 464220 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 464221 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 464225 T1266 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10089bda name:ZooKeeperConnection Watcher:127.0.0.1:53634 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 464226 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 464232 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 464235 T1268 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7db00f07 name:ZooKeeperConnection Watcher:127.0.0.1:53634 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 464236 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 464236 T1205 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 464247 T1205 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 464255 T1205 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 464261 T1205 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 464266 T1205 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 464276 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 464279 T1270 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@994a61c name:ZooKeeperConnection Watcher:127.0.0.1:53634/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 464280 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 464283 T1205 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 464291 T1205 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 464299 T1264 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 464300 T1270 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 464301 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 464305 T1272 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@291ae043 name:ZooKeeperConnection Watcher:127.0.0.1:53634/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 464305 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 464307 T1205 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 464314 T1205 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 464327 T1205 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53634_solr
[junit4] 2> 464327 T1205 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 464334 T1205 oasc.Overseer.start Overseer (id=91757605986172932-127.0.0.1:53634_solr-n_0000000000) starting
[junit4] 2> 464340 T1205 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 464351 T1205 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 464360 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 464371 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 464381 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 464391 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 464408 T1274 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 464409 T1274 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:53634_solr
[junit4] 2> 464411 T1273 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 464417 T1273 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 464419 T1273 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> 464419 T1273 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 464419 T1273 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 464425 T1272 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 464427 T1270 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> 464427 T1264 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> 464914 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 464944 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 464959 T1272 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 464961 T1205 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 464965 T1273 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 464967 T1264 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 464967 T1270 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 464971 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 464975 T1272 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 464975 T1276 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@44a77cfd name:ZooKeeperConnection Watcher:127.0.0.1:53634/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 464976 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 464979 T1205 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 464985 T1205 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 464991 T1276 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 464991 T1264 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 464997 T1272 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 464997 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 465000 T1273 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> 465001 T1273 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 465007 T1272 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 465019 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 465034 T1272 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 465054 T1272 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 465161 T1264 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> 465164 T1205 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 465165 T1276 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> 465172 T1264 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 465174 T1276 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 465179 T1205 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53634 53634
[junit4] 2> 465189 T1258 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53634 53634
[junit4] 2> 465423 T1205 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 2> 465423 T1273 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:53634_solr
[junit4] 2> 465425 T1277 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data 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:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 465431 T1205 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
[junit4] 2> 465432 T1205 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 465433 T1278 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 465536 T1205 oasc.ZkTestServer.run start zk server on port:53641
[junit4] 2> 465538 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 465544 T1284 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@68bb8a45 name:ZooKeeperConnection Watcher:127.0.0.1:53641/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 465544 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 465546 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 465549 T1286 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@77aa391b name:ZooKeeperConnection Watcher:127.0.0.1:53641 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 465549 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 465555 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 465558 T1288 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29f39ec7 name:ZooKeeperConnection Watcher:127.0.0.1:53641 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 465558 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 465558 T1205 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 465566 T1205 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 465572 T1205 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 465579 T1205 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 465584 T1205 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 465592 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 465595 T1290 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b4db343 name:ZooKeeperConnection Watcher:127.0.0.1:53641/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 465596 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 465597 T1205 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 465603 T1205 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 465614 T1205 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53641_solr
[junit4] 2> 465614 T1205 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 465620 T1205 oasc.Overseer.start Overseer (id=91757606072877059-127.0.0.1:53641_solr-n_0000000000) starting
[junit4] 2> 465625 T1205 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 465633 T1205 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 465642 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 465650 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 465659 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 465670 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 465686 T1292 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 465688 T1292 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:53641_solr
[junit4] 2> 465690 T1291 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 465694 T1205 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 465697 T1291 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 465698 T1291 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 465698 T1291 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 465705 T1290 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 465707 T1284 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 465749 T1205 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 465753 T1290 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 465758 T1291 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 465759 T1291 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"active"}
[junit4] 2> 465759 T1291 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
[junit4] 2> 465760 T1291 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 465767 T1290 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 465873 T1284 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 465915 T1205 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53641 53641
[junit4] 2> 466085 T1278 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53641 53641
[junit4] 2> 466296 T1205 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
[junit4] 2> 466296 T1291 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:53641_solr
[junit4] 2> 466298 T1293 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data 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:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 466303 T1205 oas.SolrTestCaseJ4.setUp ###Starting testPlaceholders
[junit4] 2> 466309 T1205 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 466316 T1294 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 466417 T1205 oasc.ZkTestServer.run start zk server on port:53646
[junit4] 2> 466419 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 466424 T1300 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@236d06a4 name:ZooKeeperConnection Watcher:127.0.0.1:53646/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 466425 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 466426 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 466429 T1302 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a125061 name:ZooKeeperConnection Watcher:127.0.0.1:53646 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 466430 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 466436 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 466439 T1304 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@48c123c name:ZooKeeperConnection Watcher:127.0.0.1:53646 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 466439 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 466439 T1205 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 466448 T1205 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 466455 T1205 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 466461 T1205 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 466466 T1205 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 466474 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 466478 T1306 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@78b9ab88 name:ZooKeeperConnection Watcher:127.0.0.1:53646/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 466478 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 466481 T1205 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 466487 T1205 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 466494 T1306 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 466495 T1300 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 466496 T1205 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 466501 T1308 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1852e8d2 name:ZooKeeperConnection Watcher:127.0.0.1:53646/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 466502 T1205 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 466504 T1205 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 466511 T1205 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 466523 T1205 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53646_solr
[junit4] 2> 466523 T1205 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 466529 T1205 oasc.Overseer.start Overseer (id=91757606130810884-127.0.0.1:53646_solr-n_0000000000) starting
[junit4] 2> 466535 T1205 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 466545 T1205 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 466553 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 466562 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 466571 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 466583 T1205 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 466601 T1310 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 466603 T1310 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:53646_solr
[junit4] 2> 466604 T1309 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 466611 T1309 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 466613 T1309 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=12 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"12",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 466613 T1309 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
[junit4] 2> 466613 T1309 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard9
[junit4] 2> 466621 T1308 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 466623 T1300 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> 466623 T1306 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> 467109 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard9/election
[junit4] 2> 467134 T1205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard9
[junit4] 2> 467150 T1308 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 467152 T1205 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 467154 T1309 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 467158 T1300 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 467158 T1306 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 467164 T1205 oasc.ZkTestServer.send4Le
[...truncated too long message...]
ache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:240)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.createData(DistributedQueue.java:311)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.offer(DistributedQueue.java:295)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:147)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 507735 T1578 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 507744 T1580 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:136)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2> Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leaders
[junit4] 2> at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
[junit4] 2> ... 6 more
[junit4] 2> Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leaders
[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.exists(ZooKeeper.java:1045)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:209)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:206)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:206)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:417)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:128)
[junit4] 2> at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
[junit4] 2> ... 7 more
[junit4] 2>
[junit4] 2> 507744 T1580 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 507773 T1586 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 507777 T1588 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 507780 T1590 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:136)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2> Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1
[junit4] 2> at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
[junit4] 2> ... 6 more
[junit4] 2> Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1
[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.exists(ZooKeeper.java:1045)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:209)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:206)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:206)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:417)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:128)
[junit4] 2> at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
[junit4] 2> ... 7 more
[junit4] 2>
[junit4] 2> 507781 T1590 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 509550 T1205 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.OverseerTest-5B22EF2D7D852104-001
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=en_ZA, timezone=Europe/Ljubljana
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_55 (64-bit)/cpus=2,threads=1,free=434797624,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [BinaryUpdateRequestHandlerTest, TestSurroundQueryParser, TestFoldingMultitermQuery, LeaderElectionIntegrationTest, FieldAnalysisRequestHandlerTest, TestSolrXml, DefaultValueUpdateProcessorTest, DisMaxRequestHandlerTest, SolrIndexSplitterTest, HdfsWriteToMultipleCollectionsTest, DeleteShardTest, StressHdfsTest, TestPHPSerializedResponseWriter, LeaderElectionTest, HdfsLockFactoryTest, CoreContainerCoreInitFailuresTest, BasicDistributedZkTest, TestSystemIdResolver, TestFileDictionaryLookup, DistributedExpandComponentTest, TestCharFilters, HdfsDirectoryTest, TestFieldResource, LukeRequestHandlerTest, TestJoin, ScriptEngineTest, TestShortCircuitedRequests, TestCollationField, RequiredFieldsTest, TestAnalyzeInfixSuggestions, TestSolrXMLSerializer, SynonymTokenizerTest, JsonLoaderTest, StatsComponentTest, HighlighterTest, TestSolrQueryParserDefaultOperatorResource, TestPseudoReturnFields, SuggesterTSTTest, SpellingQueryConverterTest, TestXIncludeConfig, TestCloudManagedSchema, HardAutoCommitTest, OverseerTest]
[junit4] Completed in 54.15s, 9 tests, 1 error <<< FAILURES!
[...truncated 1084 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:467: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:447: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:45: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:496: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1297: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:921: There were test failures: 390 suites, 1635 tests, 1 error, 42 ignored (15 assumptions)
Total time: 118 minutes 44 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure