You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2014/04/03 17:52:32 UTC
[JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 550 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/550/
2 tests failed.
REGRESSION: org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication
Error Message:
Exception writing document id 2001 to the index; possible analysis error.
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Exception writing document id 2001 to the index; possible analysis error.
at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:554)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:124)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
at org.apache.solr.handler.TestReplicationHandler.index(TestReplicationHandler.java:180)
at org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication(TestReplicationHandler.java:1299)
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:1617)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at java.lang.Thread.run(Thread.java:724)
FAILED: junit.framework.TestSuite.org.apache.solr.handler.TestReplicationHandler
Error Message:
7 threads leaked from SUITE scope at org.apache.solr.handler.TestReplicationHandler: 1) Thread[id=9928, name=qtp717775056-9928, state=TIMED_WAITING, group=TGRP-TestReplicationHandler] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342) at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526) at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572) at java.lang.Thread.run(Thread.java:724) 2) Thread[id=9926, name=qtp717775056-9926, state=TIMED_WAITING, group=TGRP-TestReplicationHandler] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342) at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526) at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572) at java.lang.Thread.run(Thread.java:724) 3) Thread[id=9925, name=qtp717775056-9925, state=TIMED_WAITING, group=TGRP-TestReplicationHandler] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342) at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526) at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572) at java.lang.Thread.run(Thread.java:724) 4) Thread[id=9923, name=qtp717775056-9923, state=TIMED_WAITING, group=TGRP-TestReplicationHandler] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342) at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526) at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572) at java.lang.Thread.run(Thread.java:724) 5) Thread[id=9922, name=qtp717775056-9922, state=TIMED_WAITING, group=TGRP-TestReplicationHandler] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342) at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526) at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572) at java.lang.Thread.run(Thread.java:724) 6) Thread[id=9927, name=qtp717775056-9927, state=TIMED_WAITING, group=TGRP-TestReplicationHandler] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342) at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526) at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572) at java.lang.Thread.run(Thread.java:724) 7) Thread[id=9924, name=qtp717775056-9924, state=TIMED_WAITING, group=TGRP-TestReplicationHandler] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342) at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526) at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572) at java.lang.Thread.run(Thread.java:724)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 7 threads leaked from SUITE scope at org.apache.solr.handler.TestReplicationHandler:
1) Thread[id=9928, name=qtp717775056-9928, state=TIMED_WAITING, group=TGRP-TestReplicationHandler]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
at java.lang.Thread.run(Thread.java:724)
2) Thread[id=9926, name=qtp717775056-9926, state=TIMED_WAITING, group=TGRP-TestReplicationHandler]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
at java.lang.Thread.run(Thread.java:724)
3) Thread[id=9925, name=qtp717775056-9925, state=TIMED_WAITING, group=TGRP-TestReplicationHandler]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
at java.lang.Thread.run(Thread.java:724)
4) Thread[id=9923, name=qtp717775056-9923, state=TIMED_WAITING, group=TGRP-TestReplicationHandler]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
at java.lang.Thread.run(Thread.java:724)
5) Thread[id=9922, name=qtp717775056-9922, state=TIMED_WAITING, group=TGRP-TestReplicationHandler]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
at java.lang.Thread.run(Thread.java:724)
6) Thread[id=9927, name=qtp717775056-9927, state=TIMED_WAITING, group=TGRP-TestReplicationHandler]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
at java.lang.Thread.run(Thread.java:724)
7) Thread[id=9924, name=qtp717775056-9924, state=TIMED_WAITING, group=TGRP-TestReplicationHandler]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
at java.lang.Thread.run(Thread.java:724)
at __randomizedtesting.SeedInfo.seed([6B0A471211F14034]:0)
Build Log:
[...truncated 11688 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./solrtest-TestReplicationHandler-1396536715633
[junit4] 2> 1829734 T9881 oas.SolrTestCaseJ4.setUp ###Starting doTestIndexAndConfigAliasReplication
[junit4] 2> 1829745 T9881 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1829750 T9881 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:18259
[junit4] 2> 1829751 T9881 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1829751 T9881 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1829752 T9881 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715638/master
[junit4] 2> 1829752 T9881 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715638/master/'
[junit4] 2> 1829782 T9881 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715638/master/solr.xml
[junit4] 2> 1829853 T9881 oasc.CoreContainer.<init> New CoreContainer 1034297326
[junit4] 2> 1829853 T9881 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715638/master/]
[junit4] 2> 1829855 T9881 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1829855 T9881 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1829855 T9881 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1829855 T9881 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1829856 T9881 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1829856 T9881 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1829856 T9881 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1829856 T9881 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1829857 T9881 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1829857 T9881 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1829858 T9881 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1829858 T9881 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1829863 T9891 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715638/master/collection1/'
[junit4] 2> 1829927 T9891 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1830002 T9891 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1830003 T9891 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1830008 T9891 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1830025 T9891 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1830027 T9891 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715638/master/collection1/
[junit4] 2> 1830027 T9891 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1830027 T9891 oasc.SolrCore.<init> [collection1] Opening new SolrCore at org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715638/master/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715638/master/collection1/data/
[junit4] 2> 1830027 T9891 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 1830029 T9891 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715638/master/collection1/data
[junit4] 2> 1830029 T9891 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715638/master/collection1/data/index/
[junit4] 2> 1830029 T9891 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715638/master/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 1830030 T9891 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715638/master/collection1/data/index
[junit4] 2> 1830031 T9891 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@7843fb44
[junit4] 2> 1830033 T9891 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/index5289453097tmp lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@37256b0b),segFN=segments_1,generation=1}
[junit4] 2> 1830033 T9891 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1830034 T9891 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1830034 T9891 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1830034 T9891 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1830035 T9891 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 1830035 T9891 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 1830035 T9891 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 1830035 T9891 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1830047 T9891 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1830049 T9891 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1830050 T9891 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1830050 T9891 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1300351306, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 1830052 T9891 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/index5289453097tmp lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@37256b0b),segFN=segments_1,generation=1}
[junit4] 2> 1830053 T9891 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1830053 T9891 oass.SolrIndexSearcher.<init> Opening Searcher@5d08174b[collection1] main
[junit4] 2> 1830053 T9891 oasr.ManagedResourceStorage$FileStorageIO.configure File-based storage initialized to use dir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715638/master/collection1/conf
[junit4] 2> 1830054 T9891 oasr.RestManager.init Initializing RestManager with initArgs: {storageDir=org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715638/master/collection1/conf/}
[junit4] 2> 1830054 T9891 oasr.ManagedResourceStorage.load Reading _rest_managed.json using file:dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715638/master/collection1/conf
[junit4] 2> 1830054 T9891 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 1830055 T9891 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 1830055 T9891 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 1830055 T9891 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 1830055 T9891 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 1830056 T9892 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5d08174b[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1830056 T9891 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1830056 T9881 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0
[junit4] 2> 1830057 T9881 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1830068 T9881 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1830071 T9881 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:18260
[junit4] 2> 1830072 T9881 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1830072 T9881 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1830073 T9881 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715961/slave
[junit4] 2> 1830073 T9881 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715961/slave/'
[junit4] 2> 1830090 T9881 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715961/slave/solr.xml
[junit4] 2> 1830161 T9881 oasc.CoreContainer.<init> New CoreContainer 1760485582
[junit4] 2> 1830162 T9881 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715961/slave/]
[junit4] 2> 1830164 T9881 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1830164 T9881 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1830165 T9881 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1830165 T9881 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1830165 T9881 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1830166 T9881 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1830166 T9881 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1830167 T9881 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1830167 T9881 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1830168 T9881 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1830168 T9881 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1830169 T9881 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1830175 T9903 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715961/slave/collection1/'
[junit4] 2> 1830238 T9903 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1830306 T9903 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1830307 T9903 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1830314 T9903 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1830335 T9903 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1830337 T9903 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715961/slave/collection1/
[junit4] 2> 1830337 T9903 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1830337 T9903 oasc.SolrCore.<init> [collection1] Opening new SolrCore at org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715961/slave/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715961/slave/collection1/data/
[junit4] 2> 1830338 T9903 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 1830339 T9903 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715961/slave/collection1/data
[junit4] 2> 1830340 T9903 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715961/slave/collection1/data/index/
[junit4] 2> 1830340 T9903 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715961/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 1830343 T9903 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715961/slave/collection1/data/index
[junit4] 2> 1830343 T9903 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@257d295e
[junit4] 2> 1830346 T9903 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/index5289453099tmp lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3c26ed8c),segFN=segments_1,generation=1}
[junit4] 2> 1830346 T9903 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1830348 T9903 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1830348 T9903 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1830348 T9903 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 1830349 T9903 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 1830349 T9903 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 1830349 T9903 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1830350 T9903 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1830352 T9903 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1830355 T9903 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1830356 T9903 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1830357 T9903 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1300351306, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 1830360 T9903 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/index5289453099tmp lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3c26ed8c),segFN=segments_1,generation=1}
[junit4] 2> 1830360 T9903 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1830360 T9903 oass.SolrIndexSearcher.<init> Opening Searcher@60d56135[collection1] main
[junit4] 2> 1830361 T9903 oasr.ManagedResourceStorage$FileStorageIO.configure File-based storage initialized to use dir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715961/slave/collection1/conf
[junit4] 2> 1830361 T9903 oasr.RestManager.init Initializing RestManager with initArgs: {storageDir=org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715961/slave/collection1/conf/}
[junit4] 2> 1830361 T9903 oasr.ManagedResourceStorage.load Reading _rest_managed.json using file:dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1396536715961/slave/collection1/conf
[junit4] 2> 1830362 T9903 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 1830363 T9903 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 1830363 T9903 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 1830364 T9903 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4] 2> 1830364 T9904 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@60d56135[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1830364 T9903 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1830365 T9881 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0
[junit4] 2> 1830365 T9881 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> ASYNC NEW_CORE C1898 name=collection1 org.apache.solr.core.SolrCore@62c80cfd
[junit4] 2> 1830369 T9884 C1898 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={wt=javabin&sort=id+desc&version=2&q=*:*} hits=0 status=0 QTime=1
[junit4] 2> 1830374 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[0]} 0 2
[junit4] 2> 1830397 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1]} 0 20
[junit4] 2> 1830402 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[2]} 0 2
[junit4] 2> 1830419 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[3]} 0 14
[junit4] 2> 1830424 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[4]} 0 2
[junit4] 2> 1830449 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[5]} 0 22
[junit4] 2> 1830454 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[6]} 0 2
[junit4] 2> 1830478 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[7]} 0 20
[junit4] 2> 1830484 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[8]} 0 2
[junit4] 2> 1830502 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[9]} 0 15
[junit4] 2> 1830508 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[10]} 0 2
[junit4] 2> 1830532 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[11]} 0 21
[junit4] 2> 1830537 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[12]} 0 2
[junit4] 2> 1830555 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[13]} 0 15
[junit4] 2> 1830560 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[14]} 0 2
[junit4] 2> 1830578 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[15]} 0 15
[junit4] 2> 1830583 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[16]} 0 2
[junit4] 2> 1830601 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[17]} 0 15
[junit4] 2> 1830606 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[18]} 0 2
[junit4] 2> 1830693 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[19]} 0 84
[junit4] 2> 1830699 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[20]} 0 2
[junit4] 2> 1830721 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[21]} 0 19
[junit4] 2> 1830727 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[22]} 0 2
[junit4] 2> 1830744 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[23]} 0 14
[junit4] 2> 1830749 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[24]} 0 2
[junit4] 2> 1830767 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[25]} 0 15
[junit4] 2> 1830772 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[26]} 0 2
[junit4] 2> 1830794 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[27]} 0 19
[junit4] 2> 1830799 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[28]} 0 2
[junit4] 2> 1830816 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[29]} 0 14
[junit4] 2> 1830821 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[30]} 0 2
[junit4] 2> 1830844 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[31]} 0 20
[junit4] 2> 1830849 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[32]} 0 2
[junit4] 2> 1830872 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[33]} 0 20
[junit4] 2> 1830877 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[34]} 0 2
[junit4] 2> 1830894 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[35]} 0 14
[junit4] 2> 1830899 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[36]} 0 2
[junit4] 2> 1830916 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[37]} 0 14
[junit4] 2> 1830921 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[38]} 0 2
[junit4] 2> 1830939 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[39]} 0 15
[junit4] 2> 1830944 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[40]} 0 2
[junit4] 2> 1831028 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[41]} 0 81
[junit4] 2> 1831034 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[42]} 0 3
[junit4] 2> 1831052 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[43]} 0 15
[junit4] 2> 1831058 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[44]} 0 3
[junit4] 2> 1831076 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[45]} 0 15
[junit4] 2> 1831081 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[46]} 0 2
[junit4] 2> 1831102 T9885 C1898 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=javabin&version=2&qt=/replication&command=indexversion} status=0 QTime=0
[junit4] 2> 1831105 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[47]} 0 21
[junit4] 2> 1831111 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[48]} 0 3
[junit4] 2> 1831129 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[49]} 0 15
[junit4] 2> 1831135 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[50]} 0 2
[junit4] 2> 1831159 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[51]} 0 21
[junit4] 2> 1831165 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[52]} 0 3
[junit4] 2> 1831194 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[53]} 0 27
[junit4] 2> 1831199 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[54]} 0 2
[junit4] 2> 1831278 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[55]} 0 76
[junit4] 2> 1831284 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[56]} 0 2
[junit4] 2> 1831301 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[57]} 0 14
[junit4] 2> 1831307 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[58]} 0 2
[junit4] 2> 1831324 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[59]} 0 14
[junit4] 2> 1831329 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[60]} 0 2
[junit4] 2> 1831346 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[61]} 0 14
[junit4] 2> 1831351 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[62]} 0 2
[junit4] 2> 1831368 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[63]} 0 14
[junit4] 2> 1831373 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[64]} 0 2
[junit4] 2> 1831390 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[65]} 0 14
[junit4] 2> 1831395 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[66]} 0 2
[junit4] 2> 1831417 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[67]} 0 19
[junit4] 2> 1831422 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[68]} 0 2
[junit4] 2> 1831442 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[69]} 0 17
[junit4] 2> 1831447 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[70]} 0 2
[junit4] 2> 1831470 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[71]} 0 20
[junit4] 2> 1831475 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[72]} 0 2
[junit4] 2> 1831498 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[73]} 0 20
[junit4] 2> 1831503 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[74]} 0 2
[junit4] 2> 1831585 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[75]} 0 79
[junit4] 2> 1831590 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[76]} 0 2
[junit4] 2> 1831608 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[77]} 0 15
[junit4] 2> 1831614 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[78]} 0 3
[junit4] 2> 1831633 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[79]} 0 16
[junit4] 2> 1831638 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[80]} 0 2
[junit4] 2> 1831657 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[81]} 0 15
[junit4] 2> 1831663 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[82]} 0 3
[junit4] 2> 1831681 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[83]} 0 15
[junit4] 2> 1831687 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[84]} 0 2
[junit4] 2> 1831705 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[85]} 0 15
[junit4] 2> 1831711 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[86]} 0 3
[junit4] 2> 1831736 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[87]} 0 22
[junit4] 2> 1831744 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[88]} 0 3
[junit4] 2> 1831762 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[89]} 0 15
[junit4] 2> 1831767 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[90]} 0 2
[junit4] 2> 1831849 T9884 C1898 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[91]} 0 78
[junit4] 2> ASYNC NEW_CORE C1899 name=collection1 org.apache.solr.core.SolrCore@62c80cfd
[junit4] 2> 1831866 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[92]} 0 14
[junit4] 2> 1831884 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[93]} 0 15
[junit4] 2> 1831889 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[94]} 0 2
[junit4] 2> 1831906 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[95]} 0 14
[junit4] 2> 1831912 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[96]} 0 2
[junit4] 2> 1831935 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[97]} 0 20
[junit4] 2> 1831941 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[98]} 0 2
[junit4] 2> 1831958 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[99]} 0 14
[junit4] 2> 1831963 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[100]} 0 2
[junit4] 2> 1831980 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[101]} 0 14
[junit4] 2> 1831986 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[102]} 0 2
[junit4] 2> 1832004 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[103]} 0 15
[junit4] 2> 1832009 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[104]} 0 2
[junit4] 2> 1832027 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[105]} 0 15
[junit4] 2> 1832032 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[106]} 0 2
[junit4] 2> 1832055 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[107]} 0 20
[junit4] 2> 1832060 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[108]} 0 2
[junit4] 2> 1832077 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[109]} 0 14
[junit4] 2> 1832082 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[110]} 0 2
[junit4] 2> 1832101 T9885 C1899 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=javabin&version=2&qt=/replication&command=indexversion} status=0 QTime=0
[junit4] 2> 1832171 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[111]} 0 86
[junit4] 2> 1832178 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[112]} 0 3
[junit4] 2> 1832200 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[113]} 0 20
[junit4] 2> 1832206 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[114]} 0 2
[junit4] 2> 1832224 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[115]} 0 15
[junit4] 2> 1832229 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[116]} 0 2
[junit4] 2> 1832247 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[117]} 0 15
[junit4] 2> 1832252 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[118]} 0 2
[junit4] 2> 1832270 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[119]} 0 15
[junit4] 2> 1832275 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[120]} 0 2
[junit4] 2> 1832293 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[121]} 0 15
[junit4] 2> 1832299 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[122]} 0 2
[junit4] 2> 1832317 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[123]} 0 15
[junit4] 2> 1832322 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[124]} 0 2
[junit4] 2> 1832340 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[125]} 0 15
[junit4] 2> 1832345 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[126]} 0 2
[junit4] 2> 1832428 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[127]} 0 79
[junit4] 2> 1832434 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[128]} 0 2
[junit4] 2> 1832457 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[129]} 0 20
[junit4] 2> 1832463 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[130]} 0 2
[junit4] 2> 1832493 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[131]} 0 26
[junit4] 2> 1832499 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[132]} 0 2
[junit4] 2> 1832516 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[133]} 0 14
[junit4] 2> 1832522 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[134]} 0 2
[junit4] 2> 1832539 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[135]} 0 14
[junit4] 2> 1832544 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[136]} 0 2
[junit4] 2> 1832568 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[137]} 0 21
[junit4] 2> 1832579 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[138]} 0 7
[junit4] 2> 1832598 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[139]} 0 16
[junit4] 2> 1832603 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[140]} 0 2
[junit4] 2> 1832622 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[141]} 0 16
[junit4] 2> 1832628 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[142]} 0 3
[junit4] 2> 1832646 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[143]} 0 15
[junit4] 2> 1832651 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[144]} 0 2
[junit4] 2> 1832736 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[145]} 0 82
[junit4] 2> 1832741 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[146]} 0 2
[junit4] 2> 1832760 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[147]} 0 15
[junit4] 2> 1832766 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[148]} 0 2
[junit4] 2> 1832783 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[149]} 0 14
[junit4] 2> 1832788 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[150]} 0 2
[junit4] 2> 1832807 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[151]} 0 16
[junit4] 2> 1832813 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[152]} 0 2
[junit4] 2> 1832836 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[153]} 0 20
[junit4] 2> 1832842 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[154]} 0 2
[junit4] 2> 1832866 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[155]} 0 21
[junit4] 2> 1832871 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[156]} 0 2
[junit4] 2> 1832895 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[157]} 0 21
[junit4] 2> 1832901 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[158]} 0 2
[junit4] 2> 1832925 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[159]} 0 21
[junit4] 2> 1832931 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[160]} 0 3
[junit4] 2> 1832954 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[161]} 0 20
[junit4] 2> 1832960 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[162]} 0 2
[junit4] 2> 1833055 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[163]} 0 92
[junit4] 2> 1833061 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[164]} 0 3
[junit4] 2> 1833079 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[165]} 0 15
[junit4] 2> 1833084 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[166]} 0 2
[junit4] 2> 1833101 T9885 C1899 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=javabin&version=2&qt=/replication&command=indexversion} status=0 QTime=0
[junit4] 2> 1833101 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[167]} 0 14
[junit4] 2> 1833107 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[168]} 0 2
[junit4] 2> 1833125 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[169]} 0 15
[junit4] 2> 1833130 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[170]} 0 2
[junit4] 2> 1833148 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[171]} 0 15
[junit4] 2> 1833153 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[172]} 0 2
[junit4] 2> 1833172 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[173]} 0 15
[junit4] 2> 1833178 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[174]} 0 2
[junit4] 2> 1833195 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[175]} 0 14
[junit4] 2> 1833201 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[176]} 0 2
[junit4] 2> 1833224 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[177]} 0 20
[junit4] 2> 1833230 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[178]} 0 3
[junit4] 2> 1833248 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[179]} 0 15
[junit4] 2> 1833253 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[180]} 0 2
[junit4] 2> 1833276 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[181]} 0 20
[junit4] 2> 1833281 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[182]} 0 2
[junit4] 2> 1833369 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[183]} 0 85
[junit4] 2> 1833374 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[184]} 0 2
[junit4] 2> 1833391 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[185]} 0 14
[junit4] 2> 1833397 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[186]} 0 2
[junit4] 2> 1833414 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[187]} 0 14
[junit4] 2> 1833419 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[188]} 0 2
[junit4] 2> 1833441 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[189]} 0 19
[junit4] 2> 1833446 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[190]} 0 2
[junit4] 2> 1833463 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[191]} 0 14
[junit4] 2> 1833468 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[192]} 0 2
[junit4] 2> 1833491 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[193]} 0 20
[junit4] 2> 1833496 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[194]} 0 2
[junit4] 2> 1833513 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[195]} 0 14
[junit4] 2> 1833518 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[196]} 0 2
[junit4] 2> 1833540 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[197]} 0 19
[junit4] 2> 1833546 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[198]} 0 2
[junit4] 2> 1833565 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[199]} 0 16
[junit4] 2> 1833570 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[200]} 0 2
[junit4] 2> 1833648 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[201]} 0 75
[junit4] 2> 1833653 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[202]} 0 2
[junit4] 2> 1833678 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[203]} 0 21
[junit4] 2> 1833684 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[204]} 0 2
[junit4] 2> 1833703 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[205]} 0 15
[junit4] 2> 1833708 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[206]} 0 2
[junit4] 2> 1833732 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[207]} 0 21
[junit4] 2> 1833737 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[208]} 0 2
[junit4] 2> 1833754 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[209]} 0 14
[junit4] 2> 1833760 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[210]} 0 2
[junit4] 2> 1833783 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[211]} 0 20
[junit4] 2> 1833788 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[212]} 0 2
[junit4] 2> 1833811 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[213]} 0 20
[junit4] 2> 1833817 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[214]} 0 2
[junit4] 2> 1833841 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[215]} 0 20
[junit4] 2> 1833847 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[216]} 0 2
[junit4] 2> 1833864 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[217]} 0 14
[junit4] 2> 1833869 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[218]} 0 2
[junit4] 2> 1833953 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[219]} 0 81
[junit4] 2> 1833958 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[220]} 0 2
[junit4] 2> 1833975 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[221]} 0 14
[junit4] 2> 1833980 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[222]} 0 2
[junit4] 2> 1833998 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[223]} 0 15
[junit4] 2> 1834004 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[224]} 0 2
[junit4] 2> 1834021 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[225]} 0 14
[junit4] 2> 1834027 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[226]} 0 2
[junit4] 2> 1834044 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[227]} 0 14
[junit4] 2> 1834049 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[228]} 0 2
[junit4] 2> 1834071 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[229]} 0 19
[junit4] 2> 1834076 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[230]} 0 2
[junit4] 2> 1834093 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[231]} 0 14
[junit4] 2> 1834097 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[232]} 0 2
[junit4] 2> 1834101 T9885 C1899 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=javabin&version=2&qt=/replication&command=indexversion} status=0 QTime=0
[junit4] 2> 1834124 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[233]} 0 25
[junit4] 2> 1834129 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[234]} 0 2
[junit4] 2> 1834207 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[235]} 0 75
[junit4] 2> 1834213 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[236]} 0 2
[junit4] 2> 1834237 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[237]} 0 20
[junit4] 2> 1834245 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[238]} 0 4
[junit4] 2> 1834271 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[239]} 0 22
[junit4] 2> 1834311 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[240]} 0 34
[junit4] 2> 1834329 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[241]} 0 14
[junit4] 2> 1834334 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[242]} 0 2
[junit4] 2> 1834350 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[243]} 0 13
[junit4] 2> 1834355 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[244]} 0 2
[junit4] 2> 1834372 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[245]} 0 14
[junit4] 2> 1834378 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[246]} 0 2
[junit4] 2> 1834396 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[247]} 0 15
[junit4] 2> 1834401 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[248]} 0 2
[junit4] 2> 1834418 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[249]} 0 14
[junit4] 2> 1834424 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[250]} 0 2
[junit4] 2> 1834451 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[251]} 0 23
[junit4] 2> 1834459 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[252]} 0 3
[junit4] 2> 1834545 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[253]} 0 82
[junit4] 2> 1834551 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[254]} 0 2
[junit4] 2> 1834575 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[255]} 0 21
[junit4] 2> 1834580 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[256]} 0 2
[junit4] 2> 1834597 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[257]} 0 14
[junit4] 2> 1834602 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[258]} 0 2
[junit4] 2> 1834631 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[259]} 0 26
[junit4] 2> 1834636 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[260]} 0 2
[junit4] 2> 1834653 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[261]} 0 14
[junit4] 2> 1834658 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[262]} 0 2
[junit4] 2> 1834681 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[263]} 0 20
[junit4] 2> 1834686 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[264]} 0 2
[junit4] 2> 1834703 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[265]} 0 14
[junit4] 2> 1834709 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[266]} 0 2
[junit4] 2> 1834727 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[267]} 0 15
[junit4] 2> 1834733 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[268]} 0 2
[junit4] 2> 1834751 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[269]} 0 15
[junit4] 2> 1834756 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[270]} 0 2
[junit4] 2> 1834780 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[271]} 0 21
[junit4] 2> 1834786 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[272]} 0 3
[junit4] 2> 1834809 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[273]} 0 20
[junit4] 2> 1834815 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[274]} 0 2
[junit4] 2> 1834904 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[275]} 0 86
[junit4] 2> 1834909 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[276]} 0 2
[junit4] 2> 1834932 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[277]} 0 20
[junit4] 2> 1834938 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[278]} 0 2
[junit4] 2> 1834956 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[279]} 0 15
[junit4] 2> 1834961 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[280]} 0 2
[junit4] 2> 1834979 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[281]} 0 15
[junit4] 2> 1834984 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[282]} 0 2
[junit4] 2> 1835001 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[283]} 0 14
[junit4] 2> 1835008 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[284]} 0 2
[junit4] 2> 1835025 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[285]} 0 14
[junit4] 2> 1835031 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[286]} 0 2
[junit4] 2> 1835049 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[287]} 0 15
[junit4] 2> 1835054 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[288]} 0 2
[junit4] 2> 1835074 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[289]} 0 15
[junit4] 2> 1835079 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[290]} 0 2
[junit4] 2> 1835101 T9885 C1899 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wt=javabin&version=2&qt=/replication&command=indexversion} status=0 QTime=0
[junit4] 2> 1835215 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[291]} 0 133
[junit4] 2> 1835221 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[292]} 0 3
[junit4] 2> 1835239 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[293]} 0 15
[junit4] 2> 1835245 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[294]} 0 2
[junit4] 2> 1835262 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[295]} 0 14
[junit4] 2> 1835268 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[296]} 0 2
[junit4] 2> 1835285 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[297]} 0 14
[junit4] 2> 1835290 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[298]} 0 2
[junit4] 2> 1835318 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[299]} 0 25
[junit4] 2> 1835325 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[300]} 0 3
[junit4] 2> 1835348 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[301]} 0 20
[junit4] 2> 1835353 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[302]} 0 2
[junit4] 2> 1835372 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[303]} 0 15
[junit4] 2> 1835377 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[304]} 0 2
[junit4] 2> 1835394 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[305]} 0 14
[junit4] 2> 1835399 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[306]} 0 2
[junit4] 2> 1835416 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[307]} 0 14
[junit4] 2> 1835421 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[308]} 0 2
[junit4] 2> 1835505 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[309]} 0 81
[junit4] 2> 1835511 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[310]} 0 2
[junit4] 2> 1835528 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[311]} 0 14
[junit4] 2> 1835534 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[312]} 0 2
[junit4] 2> 1835551 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[313]} 0 14
[junit4] 2> 1835557 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[314]} 0 2
[junit4] 2> 1835575 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[315]} 0 15
[junit4] 2> 1835581 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[316]} 0 3
[junit4] 2> 1835597 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[317]} 0 14
[junit4] 2> 1835603 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[318]} 0 2
[junit4] 2> 1835622 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[319]} 0 15
[junit4] 2> 1835628 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[320]} 0 2
[junit4] 2> 1835645 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[321]} 0 14
[junit4] 2> 1835650 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[322]} 0 2
[junit4] 2> 1835666 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[323]} 0 13
[junit4] 2> 1835671 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[324]} 0 2
[junit4] 2> 1835695 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[325]} 0 21
[junit4] 2> 1835700 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[326]} 0 2
[junit4] 2> 1835783 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[327]} 0 80
[junit4] 2> 1835788 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[328]} 0 2
[junit4] 2> 1835823 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[329]} 0 32
[junit4] 2> 1835828 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[330]} 0 2
[junit4] 2> 1835845 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[331]} 0 14
[junit4] 2> 1835850 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[332]} 0 2
[junit4] 2> 1835868 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[333]} 0 15
[junit4] 2> 1835873 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[334]} 0 2
[junit4] 2> 1835889 T9884 C1899 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[335]} 0 13
[junit4] 2> 1835894 T98
[...truncated too long message...]
eLikeThisHandlerTest, DOMUtilTest, StatelessScriptUpdateProcessorFactoryTest, HdfsRecoveryZkTest, TestMiniSolrCloudCluster, CustomCollectionTest, TestCollationFieldDocValues, QueryParsingTest, TestExceedMaxTermLength, TestRestManager, TestPHPSerializedResponseWriter, TestFunctionQuery, CopyFieldTest, TestImplicitCoreProperties, TestSolrDeletionPolicy1, DistributedQueryElevationComponentTest, TestGroupingSearch, AbstractAnalyticsFacetTest, HdfsWriteToMultipleCollectionsTest, TestFieldSortValues, TestConfigSets, TestExtendedDismaxParser, ReturnFieldsTest, SliceStateUpdateTest, DistributedExpandComponentTest, QueryEqualityTest, CSVRequestHandlerTest, DistributedTermsComponentTest, TestShortCircuitedRequests, TestWriterPerf, HdfsCollectionsAPIDistributedZkTest, TestSolrXmlPersistor, ResourceLoaderTest, DocumentBuilderTest, OverseerTest, SOLR749Test, TestSuggestSpellingConverter, SchemaVersionSpecificBehaviorTest, TestPostingsSolrHighlighter, CoreAdminHandlerTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, CollectionsAPIDistributedZkTest, LeaderElectionIntegrationTest, ShardRoutingTest, RecoveryZkTest, TestReplicationHandler]
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestReplicationHandler -Dtests.seed=6B0A471211F14034 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=ar_LB -Dtests.timezone=Africa/Brazzaville -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.00s J0 | TestReplicationHandler (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 7 threads leaked from SUITE scope at org.apache.solr.handler.TestReplicationHandler:
[junit4] > 1) Thread[id=9928, name=qtp717775056-9928, state=TIMED_WAITING, group=TGRP-TestReplicationHandler]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
[junit4] > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
[junit4] > at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] > 2) Thread[id=9926, name=qtp717775056-9926, state=TIMED_WAITING, group=TGRP-TestReplicationHandler]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
[junit4] > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
[junit4] > at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] > 3) Thread[id=9925, name=qtp717775056-9925, state=TIMED_WAITING, group=TGRP-TestReplicationHandler]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
[junit4] > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
[junit4] > at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] > 4) Thread[id=9923, name=qtp717775056-9923, state=TIMED_WAITING, group=TGRP-TestReplicationHandler]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
[junit4] > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
[junit4] > at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] > 5) Thread[id=9922, name=qtp717775056-9922, state=TIMED_WAITING, group=TGRP-TestReplicationHandler]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
[junit4] > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
[junit4] > at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] > 6) Thread[id=9927, name=qtp717775056-9927, state=TIMED_WAITING, group=TGRP-TestReplicationHandler]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
[junit4] > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
[junit4] > at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] > 7) Thread[id=9924, name=qtp717775056-9924, state=TIMED_WAITING, group=TGRP-TestReplicationHandler]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
[junit4] > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
[junit4] > at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool.access$600(QueuedThreadPool.java:44)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] > at __randomizedtesting.SeedInfo.seed([6B0A471211F14034]:0)
[junit4] Completed on J0 in 3584.71s, 14 tests, 2 errors <<< FAILURES!
[...truncated 11 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:474: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:447: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:45: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:496: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1275: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:907: There were test failures: 397 suites, 1674 tests, 1 suite-level error, 1 error, 35 ignored (7 assumptions)
Total time: 181 minutes 23 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 551 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/551/
1 tests failed.
REGRESSION: 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([BC3F15F2B7198C71:B8379A01A5BC6350]: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.joinElection(LeaderElector.java:267)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:156)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:667)
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:1617)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at java.lang.Thread.run(Thread.java:724)
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:31)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
... 45 more
Build Log:
[...truncated 10717 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./solrtest-OverseerTest-1396584640597
[junit4] 2> 736880 T3274 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
[junit4] 2> 736881 T3274 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 736881 T3274 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 736885 T3274 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
[junit4] 2> 736885 T3274 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 736885 T3275 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 736986 T3274 oasc.ZkTestServer.run start zk server on port:42398
[junit4] 2> 736987 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 736992 T3281 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a6c4c4d name:ZooKeeperConnection Watcher:127.0.0.1:42398/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 736992 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 736993 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 737006 T3283 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5fa0cb30 name:ZooKeeperConnection Watcher:127.0.0.1:42398 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 737006 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 737010 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 737011 T3285 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4be8b4a5 name:ZooKeeperConnection Watcher:127.0.0.1:42398 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 737011 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 737012 T3274 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 737022 T3274 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 737025 T3274 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 737027 T3274 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 737036 T3274 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 737039 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 737040 T3287 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6234750d name:ZooKeeperConnection Watcher:127.0.0.1:42398/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 737041 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 737042 T3274 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 737044 T3274 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 737054 T3274 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:42398_solr
[junit4] 2> 737055 T3274 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 737063 T3274 oasc.Overseer.start Overseer (id=91526571006951427-127.0.0.1:42398_solr-n_0000000000) starting
[junit4] 2> 737070 T3274 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 737074 T3274 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 737086 T3274 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 737089 T3274 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 737091 T3274 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 737094 T3274 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 737099 T3289 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 737100 T3289 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:42398_solr
[junit4] 2> 737100 T3288 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 737102 T3274 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 737102 T3288 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 737103 T3288 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> 737103 T3288 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 737105 T3287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 737106 T3281 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> 737155 T3274 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 737157 T3287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 737158 T3288 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 737159 T3288 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> 737159 T3288 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
[junit4] 2> 737159 T3288 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 737161 T3287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 737265 T3281 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> 737314 T3274 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42398 42398
[junit4] 2> 737531 T3275 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42398 42398
[junit4] 2> 737532 T3274 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
[junit4] 2> 737533 T3288 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:42398_solr
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 737535 T3290 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> 737541 T3274 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 737541 T3274 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 737542 T3291 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 737644 T3274 oasc.ZkTestServer.run start zk server on port:42403
[junit4] 2> 737645 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 737656 T3297 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3547495d name:ZooKeeperConnection Watcher:127.0.0.1:42403/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 737656 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 737657 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 737665 T3299 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@254f7912 name:ZooKeeperConnection Watcher:127.0.0.1:42403 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 737666 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 737904 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 737906 T3301 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c846b41 name:ZooKeeperConnection Watcher:127.0.0.1:42403 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 737906 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 737907 T3274 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 737914 T3274 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 737918 T3274 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 737926 T3274 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 737929 T3274 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 737933 T3274 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 737954 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 737957 T3303 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3bb12d55 name:ZooKeeperConnection Watcher:127.0.0.1:42403/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 737957 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 737958 T3274 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 737961 T3274 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 737974 T3274 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:42403_solr
[junit4] 2> 737974 T3274 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 737982 T3274 oasc.Overseer.start Overseer (id=91526571049943043-127.0.0.1:42403_solr-n_0000000000) starting
[junit4] 2> 737991 T3274 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 738003 T3274 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 738015 T3274 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 738019 T3274 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 738029 T3274 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 738034 T3305 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 738035 T3305 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:42403_solr
[junit4] 2> 738036 T3304 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 738037 T3304 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 738038 T3304 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> 738039 T3297 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> 738042 T3304 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> 738043 T3297 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> 738044 T3304 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 738046 T3304 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 738046 T3304 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> 738049 T3303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 738050 T3297 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> 738149 T3274 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42403 42403
[junit4] 2> 738221 T3291 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42403 42403
[junit4] 2> 738222 T3274 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 2> 738223 T3304 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:42403_solr
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 738225 T3306 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> 738232 T3274 oas.SolrTestCaseJ4.setUp ###Starting testPlaceholders
[junit4] 2> 738232 T3274 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 738233 T3307 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 738334 T3274 oasc.ZkTestServer.run start zk server on port:42408
[junit4] 2> 738335 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 738343 T3313 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b5ff5d4 name:ZooKeeperConnection Watcher:127.0.0.1:42408/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 738343 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 738344 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 738353 T3315 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@73849408 name:ZooKeeperConnection Watcher:127.0.0.1:42408 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 738353 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 738397 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 738398 T3317 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@75cf4e07 name:ZooKeeperConnection Watcher:127.0.0.1:42408 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 738399 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 738399 T3274 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 738403 T3274 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 738406 T3274 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 738408 T3274 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 738409 T3274 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 738412 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 738414 T3319 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4232a41a name:ZooKeeperConnection Watcher:127.0.0.1:42408/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 738415 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 738416 T3274 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 738417 T3274 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 738420 T3313 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 738420 T3319 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 738420 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 738422 T3321 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6858fe86 name:ZooKeeperConnection Watcher:127.0.0.1:42408/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 738422 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 738423 T3274 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 738425 T3274 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 738429 T3274 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:42408_solr
[junit4] 2> 738429 T3274 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 738431 T3274 oasc.Overseer.start Overseer (id=91526571095425028-127.0.0.1:42408_solr-n_0000000000) starting
[junit4] 2> 738433 T3274 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 738436 T3274 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 738439 T3274 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 738441 T3274 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 738444 T3274 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 738447 T3274 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 738463 T3323 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 738470 T3323 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:42408_solr
[junit4] 2> 738470 T3322 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 738480 T3322 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 738481 T3322 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> 738481 T3322 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
[junit4] 2> 738482 T3322 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard9
[junit4] 2> 738485 T3321 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 738491 T3319 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> 738491 T3313 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> 738980 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard9/election
[junit4] 2> 739005 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard9
[junit4] 2> 739023 T3321 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 739024 T3274 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 739025 T3322 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 739033 T3313 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 739033 T3319 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 739053 T3274 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42408 42408
[junit4] 2> 740527 T3322 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /clusterstate.json
[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.common.cloud.ClusterState.load(ClusterState.java:239)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.updateClusterState(ZkStateReader.java:422)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.updateClusterState(ZkStateReader.java:240)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:233)
[junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4] 2>
[junit4] 2> 741398 T3322 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:42408_solr
[junit4] 2> 741399 T3307 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42408 42408
[junit4] 2> 741401 T3324 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> 741401 T3274 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 741409 T3274 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
[junit4] 2> 741409 T3274 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 741410 T3325 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 741511 T3274 oasc.ZkTestServer.run start zk server on port:42414
[junit4] 2> 741512 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 741516 T3331 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@47440836 name:ZooKeeperConnection Watcher:127.0.0.1:42414/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 741516 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 741517 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 741519 T3333 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b3d8fdb name:ZooKeeperConnection Watcher:127.0.0.1:42414 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 741520 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 741597 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 741599 T3335 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@762864d8 name:ZooKeeperConnection Watcher:127.0.0.1:42414 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 741599 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 741600 T3274 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 741602 T3274 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 741604 T3274 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 741606 T3274 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 741608 T3274 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 741610 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 741612 T3337 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@53bc72a8 name:ZooKeeperConnection Watcher:127.0.0.1:42414/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 741612 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 741613 T3274 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 741615 T3274 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 741624 T3331 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 741624 T3337 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 741625 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 741630 T3339 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7bb75e1 name:ZooKeeperConnection Watcher:127.0.0.1:42414/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 741630 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 741631 T3274 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 741641 T3274 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 741670 T3274 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:42414_solr
[junit4] 2> 741671 T3274 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 741679 T3274 oasc.Overseer.start Overseer (id=91526571303829508-127.0.0.1:42414_solr-n_0000000000) starting
[junit4] 2> 741694 T3274 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 741710 T3274 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 741714 T3274 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 741725 T3274 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 741734 T3274 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 741745 T3274 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 741763 T3341 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 741764 T3341 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:42414_solr
[junit4] 2> 741764 T3340 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 741766 T3340 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 741767 T3340 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> 741767 T3340 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 741767 T3340 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 741776 T3339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 741778 T3331 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> 741778 T3337 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> 742267 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 742292 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 742314 T3339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 742314 T3274 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 742315 T3340 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 742315 T3331 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 742316 T3337 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 742326 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 742328 T3343 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@25ec31ef name:ZooKeeperConnection Watcher:127.0.0.1:42414/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 742328 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 742335 T3339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 742335 T3274 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 742336 T3274 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 742339 T3331 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 742340 T3343 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 742349 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 742349 T3339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 742350 T3340 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> 742350 T3340 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 742368 T3339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 742369 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 742380 T3339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 742391 T3339 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 742519 T3343 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> 742519 T3331 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> 742520 T3274 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 742593 T3331 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 742593 T3343 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 742646 T3274 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42414 42414
[junit4] 2> 742731 T3325 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42414 42414
[junit4] 2> 742733 T3274 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 2> 742734 T3340 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:42414_solr
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 742735 T3344 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> 742741 T3274 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 742741 T3274 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 742742 T3345 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 742843 T3274 oasc.ZkTestServer.run start zk server on port:42421
[junit4] 2> 742844 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 742850 T3351 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d96c27 name:ZooKeeperConnection Watcher:127.0.0.1:42421/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 742850 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 742852 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 742854 T3353 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@745eee21 name:ZooKeeperConnection Watcher:127.0.0.1:42421 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 742854 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 742930 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 742941 T3355 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5d58c715 name:ZooKeeperConnection Watcher:127.0.0.1:42421 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 742941 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 742942 T3274 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 742945 T3274 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 742956 T3356 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 742957 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 742959 T3359 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a845b49 name:ZooKeeperConnection Watcher:127.0.0.1:42421/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 742959 T3356 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 742968 T3360 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@67852338 name:ZooKeeperConnection Watcher:127.0.0.1:42421/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 742968 T3356 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 742968 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 742970 T3274 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 742971 T3356 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 742982 T3274 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 742991 T3356 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:42421_solr
[junit4] 2> 742991 T3274 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 742991 T3356 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 742998 T3356 oasc.Overseer.start Overseer (id=91526571391844355-127.0.0.1:42421_solr-n_0000000000) starting
[junit4] 2> 742998 T3274 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 743010 T3356 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 743010 T3360 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 743011 T3274 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 743026 T3356 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 743038 T3356 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 743042 T3356 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 743054 T3356 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 743057 T3356 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 743062 T3362 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 743062 T3356 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 743063 T3362 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:42421_solr
[junit4] 2> 743064 T3356 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 743066 T3364 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6c856dda name:ZooKeeperConnection Watcher:127.0.0.1:42421/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 743066 T3356 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 743067 T3362 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer java.lang.InterruptedException: sleep interrupted
[junit4] 2> at java.lang.Thread.sleep(Native Method)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryDelay(ZkCmdExecutor.java:119)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:87)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:223)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:294)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:207)
[junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4] 2>
[junit4] 2> 743071 T3356 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:42421_solr
[junit4] 2> 743071 T3356 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 743073 T3356 oasc.Overseer.start Overseer (id=91526571391844357-127.0.0.1:42421_solr-n_0000000001) starting
[junit4] 2> 743139 T3366 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 743140 T3366 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:42421_solr
[junit4] 2> 743140 T3365 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 743142 T3365 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 743143 T3365 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 743143 T3365 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 743144 T3365 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 743156 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 743164 T3360 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> 743528 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 743556 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 743576 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 743579 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 743579 T3365 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 743579 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 743597 T3365 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 743598 T3365 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 743623 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 743624 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 743633 T3368 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@88cb2ef name:ZooKeeperConnection Watcher:127.0.0.1:42421/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 743633 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 743635 T3274 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 743637 T3274 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 743640 T3360 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 743640 T3368 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 743650 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 743650 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 743651 T3365 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 743651 T3365 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 743663 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 743665 T3274 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 743767 T3360 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 743767 T3368 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 743866 T3274 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 743870 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 743870 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 743871 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 743872 T3365 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 743872 T3365 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 743872 T3365 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 743873 T3365 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 743887 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 743990 T3368 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 743990 T3360 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 744371 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 744385 T3368 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 744385 T3360 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 744392 T3274 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 744399 T3368 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 744422 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 744422 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 744423 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 744424 T3365 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 744438 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 744542 T3368 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> 744600 T3274 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 744602 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 744604 T3370 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55d4297c name:ZooKeeperConnection Watcher:127.0.0.1:42421/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 744604 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 744605 T3274 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 744607 T3274 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 744610 T3368 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 744610 T3370 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 744618 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 744619 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 744619 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 744619 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 744620 T3365 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 744620 T3365 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 744621 T3365 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 744633 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 744635 T3370 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 744635 T3368 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 744651 T3370 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 744652 T3364 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 744652 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 744653 T3365 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 744654 T3365 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 744658 T3356 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 744671 T3356 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 744676 T3372 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ae8e27 name:ZooKeeperConnection Watcher:127.0.0.1:42421/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 744677 T3356 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 744677 T3365 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:42421_solr
[junit4] 2> 744679 T3373 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> 744710 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 744711 T3356 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:42421_solr
[junit4] 2> 744711 T3356 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 744712 T3375 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4bbebf8f name:ZooKeeperConnection Watcher:127.0.0.1:42421/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 744713 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 744721 T3356 oasc.Overseer.start Overseer (id=91526571391844360-127.0.0.1:42421_solr-n_0000000002) starting
[junit4] 2> 744721 T3274 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 744733 T3274 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 744746 T3370 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 744746 T3375 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 744760 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 744771 T3377 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 744772 T3377 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:42421_solr
[junit4] 2> 744774 T3376 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 744774 T3274 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 744775 T3376 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 744775 T3376 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 744776 T3376 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 744777 T3375 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 744777 T3370 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 744780 T3376 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 744780 T3376 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 744781 T3370 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 744781 T3375 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 744791 T3376 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 744792 T3376 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 744793 T3376 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 744793 T3376 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 744796 T3372 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 744804 T3370 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 744804 T3375 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 744807 T3376 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 744809 T3372 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 744810 T3376 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 744810 T3376 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 744812 T3372 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 744915 T3375 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 744915 T3370 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 744977 T3274 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 744981 T3372 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 744981 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 744981 T3372 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 744982 T3372 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 744983 T3376 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 744991 T3376 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 744992 T3376 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 745007 T3372 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 745007 T3375 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 745007 T3370 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 745008 T3370 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> 745009 T3274 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 745009 T3370 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> 745010 T3375 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 745021 T3372 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 745029 T3372 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 745132 T3375 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> 745211 T3274 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 745213 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 745215 T3379 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@787f9e8d name:ZooKeeperConnection Watcher:127.0.0.1:42421/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 745215 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 745216 T3274 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 745218 T3274 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 745221 T3379 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 745222 T3375 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 745231 T3372 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 745231 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 745231 T3372 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 745232 T3372 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 745233 T3376 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 745235 T3376 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 745235 T3376 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 745247 T3372 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 745247 T3375 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 745247 T3379 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 745259 T3379 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 745269 T3372 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 745269 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 745271 T3376 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 745271 T3376 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 745279 T3356 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 745280 T3356 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 745291 T3381 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@505a27c8 name:ZooKeeperConnection Watcher:127.0.0.1:42421/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 745291 T3356 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 745292 T3376 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:42421_solr
[junit4] 2> 745294 T3382 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> 745303 T3274 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 745311 T3356 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:42421_solr
[junit4] 2> 745312 T3356 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 745312 T3384 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b88c428 name:ZooKeeperConnection Watcher:127.0.0.1:42421/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 745313 T3274 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 745314 T3356 oasc.Overseer.start Overseer (id=91526571391844363-127.0.0.1:42421_solr-n_0000000003) starting
[junit4] 2> 745314 T3274 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 745325 T3274 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 745334 T3379 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 745335 T3384 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 745337 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 745340 T3386 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 745341 T3386 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:42421_solr
[junit4] 2> 745342 T3385 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 745343 T3385 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 745343 T3274 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 745344 T3385 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 745344 T3385 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 745345 T3379 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 745345 T3384 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 745347 T3385 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 745348 T3385 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 745348 T3384 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 745349 T3379 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 745350 T3385 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 745351 T3385 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 745352 T3385 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 745352 T3385 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 745355 T3381 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 745355 T3384 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 745355 T3379 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 745358 T3385 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 745370 T3381 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 745371 T3385 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_
[...truncated too long message...]
aders/shard1
[junit4] 2> 779529 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 780533 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 781536 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 782539 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 783563 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 784566 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 785570 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 786574 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 787578 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 788581 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 789585 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 790588 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 791592 T3274 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 791596 T3791 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 791605 T3789 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 791609 T3274 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42567 42567
[junit4] 2> 791678 T3779 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42567 42567
[junit4] 2> 791680 T3274 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
[junit4] 2> 791681 T3799 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:42567_solr
[junit4] 2> 791681 T3801 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] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=BC3F15F2B7198C71 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=en -Dtests.timezone=Asia/Calcutta -Dtests.file.encoding=US-ASCII
[junit4] ERROR 20.0s J0 | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
[junit4] > at __randomizedtesting.SeedInfo.seed([BC3F15F2B7198C71:B8379A01A5BC6350]:0)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:136)
[junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
[junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:156)
[junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:667)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
[junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:128)
[junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
[junit4] > ... 45 more
[junit4] 2> 791696 T3274 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 791697 T3274 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 794698 T3274 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene41, sim=DefaultSimilarity, locale=en, timezone=Asia/Calcutta
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=188084888,total=340328448
[junit4] 2> NOTE: All tests run in this JVM: [SoftAutoCommitTest, TestSearchPerf, CustomCollectionTest, TestPHPSerializedResponseWriter, TestSystemIdResolver, UpdateParamsTest, TestFaceting, ShowFileRequestHandlerTest, TestSchemaVersionResource, TestDocumentBuilder, IndexSchemaTest, TestCursorMarkWithoutUniqueKey, ZkControllerTest, QueryEqualityTest, DistribDocExpirationUpdateProcessorTest, LegacyHTMLStripCharFilterTest, SolrIndexSplitterTest, SynonymTokenizerTest, HdfsBasicDistributedZk2Test, TestMergePolicyConfig, TestNRTOpen, DeleteInactiveReplicaTest, SuggesterTest, DocExpirationUpdateProcessorFactoryTest, TestJoin, BasicFunctionalityTest, TestLMDirichletSimilarityFactory, TestBM25SimilarityFactory, UUIDFieldTest, TestElisionMultitermQuery, TestPerFieldSimilarity, TestStressVersions, MoreLikeThisHandlerTest, HdfsWriteToMultipleCollectionsTest, TestManagedSchemaFieldResource, TestExtendedDismaxParser, OverseerRolesTest, TestSolrXmlPersistor, SearchHandlerTest, TestCollationFieldDocValues, ScriptEngineTest, ResponseLogComponentTest, TestReversedWildcardFilterFactory, TestRemoteStreaming, HdfsRecoveryZkTest, BadComponentTest, TestSolrDeletionPolicy1, HdfsChaosMonkeySafeLeaderTest, TestSolrXMLSerializer, TestDynamicFieldCollectionResource, BinaryUpdateRequestHandlerTest, ReturnFieldsTest, DocumentBuilderTest, SystemInfoHandlerTest, MBeansHandlerTest, UnloadDistributedZkTest, SchemaVersionSpecificBehaviorTest, ClusterStateTest, TestExceedMaxTermLength, TestGroupingSearch, RemoteQueryErrorTest, SuggesterFSTTest, BlockCacheTest, TestPseudoReturnFields, SliceStateTest, PrimitiveFieldTypeTest, LoggingHandlerTest, TestWriterPerf, InfoHandlerTest, SolrInfoMBeanTest, RegexBoostProcessorTest, TestFieldTypeCollectionResource, LeaderElectionTest, TestJmxMonitoredMap, TestNonNRTOpen, UpdateRequestProcessorFactoryTest, OverseerCollectionProcessorTest, TestQueryUtils, OverseerTest]
[junit4] Completed on J0 in 57.90s, 9 tests, 1 error <<< FAILURES!
[...truncated 970 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:474: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:447: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:45: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:496: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1275: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:907: There were test failures: 397 suites, 1674 tests, 1 error, 35 ignored (7 assumptions)
Total time: 174 minutes 39 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure