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

[JENKINS] Lucene-Solr-4.x-Linux (64bit/ibm-j9-jdk7) - Build # 9574 - Failure!

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

1 tests failed.
REGRESSION:  org.apache.solr.update.HardAutoCommitTest.testCommitWithin

Error Message:
Exception during query

Stack Trace:
java.lang.RuntimeException: Exception during query
	at __randomizedtesting.SeedInfo.seed([235C4D9D08B437EE:998E22E58B9AD9FB]:0)
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:712)
	at org.apache.solr.update.HardAutoCommitTest.testCommitWithin(HardAutoCommitTest.java:79)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:613)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:780)
Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=0]
	xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">2455</int></lst><result name="response" numFound="1" start="0"><doc><int name="id">529</int><int name="range_facet_si">529</int><arr name="range_facet_l"><long>529</long></arr><arr name="range_facet_sl"><long>529</long></arr><arr name="field_t"><str>what's inside?</str></arr><arr name="subject"><str>info</str></arr><long name="_version_">1461718508573294592</long><int name="intDefault">42</int><date name="timestamp">2014-03-05T07:09:59.442Z</date><arr name="multiDefault"><str>muLti-Default</str></arr></doc></result>
</response>

	request was:qt=standard&start=0&q=id:529&version=2.2&rows=20
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:705)
	... 41 more




Build Log:
[...truncated 10863 lines...]
   [junit4] Suite: org.apache.solr.update.HardAutoCommitTest
   [junit4]   2> 460450 T1238 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
   [junit4]   2> 460451 T1238 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1394003396841
   [junit4]   2> 460452 T1238 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 460452 T1238 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
   [junit4]   2> 460453 T1238 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 460453 T1238 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 460489 T1238 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 460538 T1238 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 460539 T1238 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 460545 T1238 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 460911 T1238 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 460912 T1238 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 460913 T1238 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 460919 T1238 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 460923 T1238 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 460928 T1238 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 460932 T1238 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 460936 T1238 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 460937 T1238 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 460937 T1238 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 460938 T1238 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 460938 T1238 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 460939 T1238 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 460939 T1238 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 460939 T1238 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr
   [junit4]   2> 460940 T1238 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/'
   [junit4]   2> 460979 T1238 oasc.CoreContainer.<init> New CoreContainer 962731585
   [junit4]   2> 460979 T1238 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/]
   [junit4]   2> 460980 T1238 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 460981 T1238 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 460981 T1238 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 460982 T1238 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 460982 T1238 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 460982 T1238 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 460983 T1238 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 460983 T1238 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 460984 T1238 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 460989 T1238 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 460989 T1238 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 460989 T1238 oasc.CoreContainer.load Host Name: 
   [junit4]   2> 460993 T1239 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1
   [junit4]   2> 460993 T1239 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 460994 T1239 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
   [junit4]   2> 460994 T1239 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 460995 T1239 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 461030 T1239 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 461078 T1239 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 461079 T1239 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 461085 T1239 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 461405 T1239 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 461405 T1239 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 461406 T1239 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 461411 T1239 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 461414 T1239 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 461420 T1239 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 461423 T1239 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 461426 T1239 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 461427 T1239 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 461427 T1239 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 461427 T1239 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 461428 T1239 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 461428 T1239 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 461429 T1239 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 461429 T1239 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1394003396841/
   [junit4]   2> 461429 T1239 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7ec5da63
   [junit4]   2> 461430 T1239 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1394003396841
   [junit4]   2> 461430 T1239 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1394003396841/index/
   [junit4]   2> 461431 T1239 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1394003396841/index' doesn't exist. Creating new index...
   [junit4]   2> 461431 T1239 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1394003396841/index
   [junit4]   2> 461432 T1239 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=21, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 461432 T1239 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@447cfc68 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@ae62c2f6)),segFN=segments_1,generation=1}
   [junit4]   2> 461433 T1239 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 461433 T1239 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
   [junit4]   2> 461435 T1239 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 461436 T1239 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 461436 T1239 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 461437 T1239 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 461437 T1239 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 461437 T1239 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 461438 T1239 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 461438 T1239 oasup.UniqFieldsUpdateProcessorFactory.init WARN Use of the 'fields' init param in UniqFieldsUpdateProcessorFactory is deprecated, please use 'fieldName' (or another FieldMutatingUpdateProcessorFactory selector option) instead
   [junit4]   2> 461438 T1239 oasup.UniqFieldsUpdateProcessorFactory.init Replacing 'fields' init param with (individual) 'fieldName' params
   [junit4]   2> 461439 T1239 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 461439 T1239 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 461440 T1239 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 461440 T1239 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 461440 T1239 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 461441 T1239 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 461441 T1239 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 461441 T1239 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 461442 T1239 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 461442 T1239 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
   [junit4]   2> 461443 T1239 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
   [junit4]   2> 461443 T1239 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 461443 T1239 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 461444 T1239 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 461444 T1239 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 461445 T1239 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 461445 T1239 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 461445 T1239 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 461446 T1239 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 461446 T1239 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 461447 T1239 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 461447 T1239 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 461447 T1239 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 461448 T1239 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 461448 T1239 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 461449 T1239 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
   [junit4]   2> 461449 T1239 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
   [junit4]   2> 461450 T1239 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 461452 T1239 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 461454 T1239 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 461454 T1239 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 461455 T1239 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=24, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=34.9013671875, floorSegmentMB=0.98046875, forceMergeDeletesPctAllowed=4.043233449858429, segmentsPerTier=42.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 461455 T1239 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@447cfc68 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@ae62c2f6)),segFN=segments_1,generation=1}
   [junit4]   2> 461456 T1239 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 461456 T1239 oass.SolrIndexSearcher.<init> Opening Searcher@90c6b7d8[collection1] main
   [junit4]   2> 461457 T1239 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 461560 T1239 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 461579 T1240 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@90c6b7d8[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 461582 T1239 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 461584 T1238 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 461588 T1238 oas.SolrTestCaseJ4.setUp ###Starting testCommitWithin
   [junit4]   2> ASYNC  NEW_CORE C1024 name=collection1 org.apache.solr.core.SolrCore@1aee6d3
   [junit4]   2> 461589 T1238 C1024 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:* (-1461718507037130752)} 0 1
   [junit4]   2> 461595 T1238 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1
   [junit4]   2> 461595 T1238 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 461596 T1238 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
   [junit4]   2> 461596 T1238 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 461597 T1238 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 461634 T1238 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 461684 T1238 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 461685 T1238 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 461691 T1238 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 462075 T1238 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 462075 T1238 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 462076 T1238 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 462081 T1238 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 462084 T1238 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 462090 T1238 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 462093 T1238 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 462097 T1238 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 462097 T1238 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 462098 T1238 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 462098 T1238 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 462099 T1238 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 462099 T1238 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 462100 T1238 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1394003396841/
   [junit4]   2> 462100 T1238 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7ec5da63
   [junit4]   2> 462101 T1238 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1394003396841/index/
   [junit4]   2> 462101 T1238 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
   [junit4]   2> 462104 T1238 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 462105 T1238 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 462105 T1238 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 462106 T1238 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 462106 T1238 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 462106 T1238 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 462107 T1238 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 462107 T1238 oasup.UniqFieldsUpdateProcessorFactory.init WARN Use of the 'fields' init param in UniqFieldsUpdateProcessorFactory is deprecated, please use 'fieldName' (or another FieldMutatingUpdateProcessorFactory selector option) instead
   [junit4]   2> 462108 T1238 oasup.UniqFieldsUpdateProcessorFactory.init Replacing 'fields' init param with (individual) 'fieldName' params
   [junit4]   2> 462108 T1238 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 462109 T1238 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 462109 T1238 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 462110 T1238 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 462110 T1238 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 462111 T1238 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 462111 T1238 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 462112 T1238 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 462112 T1238 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 462113 T1238 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
   [junit4]   2> 462114 T1238 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
   [junit4]   2> 462114 T1238 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 462115 T1238 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 462115 T1238 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 462116 T1238 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 462116 T1238 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 462117 T1238 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 462117 T1238 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 462118 T1238 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 462119 T1238 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 462119 T1238 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 462120 T1238 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 462120 T1238 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 462121 T1238 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 462122 T1238 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 462122 T1238 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
   [junit4]   2> 462123 T1238 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
   [junit4]   2> 462124 T1238 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 462126 T1238 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 462127 T1238 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 462128 T1238 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 462129 T1238 oass.SolrIndexSearcher.<init> Opening Searcher@e0a60225[collection1] main
   [junit4]   2> 462129 T1238 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 462130 T1238 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 462137 T1242 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e0a60225[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 462142 T1238 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
   [junit4]   2> 462143 T1238 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
   [junit4]   2> 462143 T1238 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
   [junit4]   2> 462144 T1238 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=37, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=70.3740234375, floorSegmentMB=0.673828125, forceMergeDeletesPctAllowed=23.297181458392707, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7241821901111695
   [junit4]   2> 462145 T1238 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@447cfc68 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@ae62c2f6)),segFN=segments_1,generation=1}
   [junit4]   2> 462145 T1238 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 462146 T1238 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 462147 T1238 oass.SolrIndexSearcher.<init> Opening Searcher@168a882f[collection1] main
   [junit4]   2> 462148 T1238 oasc.CoreContainer.registerCore replacing core: collection1
   [junit4]   2> 462148 T1238 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@1aee6d3
   [junit4]   2> 462149 T1242 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@168a882f[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 462154 T1238 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=1,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
   [junit4]   2> 462155 T1238 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 463054 T1238 oasup.LogUpdateProcessor.finish [collection1] {add=[529 (1461718508573294592)]} 0 897
   [junit4]   2> 465054 T1243 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 465058 T1243 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@447cfc68 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@ae62c2f6)),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@447cfc68 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@ae62c2f6)),segFN=segments_2,generation=2}
   [junit4]   2> 465059 T1243 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 465061 T1243 oass.SolrIndexSearcher.<init> Opening Searcher@8d46b38f[collection1] main
   [junit4]   2> 465062 T1243 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 465063 T1242 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@8d46b38f[collection1] main{StandardDirectoryReader(segments_2:3:nrt _0(4.8):C1)}
   [junit4]   2> ASYNC  NEW_CORE C1025 name=collection1 org.apache.solr.core.SolrCore@29b3a484
   [junit4]   2> 465510 T1238 C1025 oasc.SolrCore.execute [collection1] webapp=null path=null params={qt=standard&start=0&q=id:529&version=2.2&rows=20} hits=1 status=0 QTime=2455 
   [junit4]   2> 465525 T1238 oas.SolrTestCaseJ4.assertQ ERROR REQUEST FAILED: xpath=//result[@numFound=0]
   [junit4]   2> 		xml response was: <?xml version="1.0" encoding="UTF-8"?>
   [junit4]   2> 	<response>
   [junit4]   2> 	<lst name="responseHeader"><int name="status">0</int><int name="QTime">2455</int></lst><result name="response" numFound="1" start="0"><doc><int name="id">529</int><int name="range_facet_si">529</int><arr name="range_facet_l"><long>529</long></arr><arr name="range_facet_sl"><long>529</long></arr><arr name="field_t"><str>what's inside?</str></arr><arr name="subject"><str>info</str></arr><long name="_version_">1461718508573294592</long><int name="intDefault">42</int><date name="timestamp">2014-03-05T07:09:59.442Z</date><arr name="multiDefault"><str>muLti-Default</str></arr></doc></result>
   [junit4]   2> 	</response>
   [junit4]   2> 	
   [junit4]   2> 		request was:qt=standard&start=0&q=id:529&version=2.2&rows=20
   [junit4]   2> 465526 T1238 oasc.SolrException.log ERROR REQUEST FAILED: qt=standard&start=0&q=id:529&version=2.2&rows=20:java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=0]
   [junit4]   2> 		xml response was: <?xml version="1.0" encoding="UTF-8"?>
   [junit4]   2> 	<response>
   [junit4]   2> 	<lst name="responseHeader"><int name="status">0</int><int name="QTime">2455</int></lst><result name="response" numFound="1" start="0"><doc><int name="id">529</int><int name="range_facet_si">529</int><arr name="range_facet_l"><long>529</long></arr><arr name="range_facet_sl"><long>529</long></arr><arr name="field_t"><str>what's inside?</str></arr><arr name="subject"><str>info</str></arr><long name="_version_">1461718508573294592</long><int name="intDefault">42</int><date name="timestamp">2014-03-05T07:09:59.442Z</date><arr name="multiDefault"><str>muLti-Default</str></arr></doc></result>
   [junit4]   2> 	</response>
   [junit4]   2> 	
   [junit4]   2> 		request was:qt=standard&start=0&q=id:529&version=2.2&rows=20
   [junit4]   2> 		at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:705)
   [junit4]   2> 		at org.apache.solr.update.HardAutoCommitTest.testCommitWithin(HardAutoCommitTest.java:79)
   [junit4]   2> 		at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]   2> 		at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
   [junit4]   2> 		at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
   [junit4]   2> 		at java.lang.reflect.Method.invoke(Method.java:613)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
   [junit4]   2> 		at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
   [junit4]   2> 		at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
   [junit4]   2> 		at java.lang.Thread.run(Thread.java:780)
   [junit4]   2> 	
   [junit4]   2> 465526 T1238 oas.SolrTestCaseJ4.tearDown ###Ending testCommitWithin
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=HardAutoCommitTest -Dtests.method=testCommitWithin -Dtests.seed=235C4D9D08B437EE -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en_NZ -Dtests.timezone=Europe/Minsk -Dtests.file.encoding=UTF-8
   [junit4] ERROR   3.95s J1 | HardAutoCommitTest.testCommitWithin <<<
   [junit4]    > Throwable #1: java.lang.RuntimeException: Exception during query
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([235C4D9D08B437EE:998E22E58B9AD9FB]:0)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:712)
   [junit4]    > 	at org.apache.solr.update.HardAutoCommitTest.testCommitWithin(HardAutoCommitTest.java:79)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:780)
   [junit4]    > Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=0]
   [junit4]    > 	xml response was: <?xml version="1.0" encoding="UTF-8"?>
   [junit4]    > <response>
   [junit4]    > <lst name="responseHeader"><int name="status">0</int><int name="QTime">2455</int></lst><result name="response" numFound="1" start="0"><doc><int name="id">529</int><int name="range_facet_si">529</int><arr name="range_facet_l"><long>529</long></arr><arr name="range_facet_sl"><long>529</long></arr><arr name="field_t"><str>what's inside?</str></arr><arr name="subject"><str>info</str></arr><long name="_version_">1461718508573294592</long><int name="intDefault">42</int><date name="timestamp">2014-03-05T07:09:59.442Z</date><arr name="multiDefault"><str>muLti-Default</str></arr></doc></result>
   [junit4]    > </response>
   [junit4]    > 	request was:qt=standard&start=0&q=id:529&version=2.2&rows=20
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:705)
   [junit4]    > 	... 41 more
   [junit4]   2> 465533 T1238 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 465533 T1238 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=962731585
   [junit4]   2> 465533 T1238 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@29b3a484
   [junit4]   2> 465542 T1238 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=1,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=1,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=151,transaction_logs_total_number=1}
   [junit4]   2> 465543 T1238 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 465543 T1238 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 465544 T1238 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 465544 T1238 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 465545 T1238 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 465546 T1238 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1394003396841 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1394003396841;done=false>>]
   [junit4]   2> 465546 T1238 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1394003396841
   [junit4]   2> 465547 T1238 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1394003396841/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1394003396841/index;done=false>>]
   [junit4]   2> 465547 T1238 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-HardAutoCommitTest-1394003396841/index
   [junit4]   2> NOTE: test params are: codec=Lucene46: {text=PostingsFormat(name=MockSep), id=PostingsFormat(name=Direct), timestamp=Pulsing41(freqCutoff=11 minBlockSize=84 maxBlockSize=231), subject=PostingsFormat(name=FSTPulsing41), field_t=PostingsFormat(name=MockSep), _version_=Pulsing41(freqCutoff=11 minBlockSize=84 maxBlockSize=231), range_facet_si=PostingsFormat(name=FSTPulsing41), range_facet_l=Pulsing41(freqCutoff=11 minBlockSize=84 maxBlockSize=231), multiDefault=PostingsFormat(name=FSTPulsing41), range_facet_sl=PostingsFormat(name=MockSep), intDefault=Pulsing41(freqCutoff=11 minBlockSize=84 maxBlockSize=231)}, docValues:{}, sim=DefaultSimilarity, locale=en_NZ, timezone=Europe/Minsk
   [junit4]   2> NOTE: Linux 3.8.0-36-generic amd64/IBM Corporation 1.7.0 (64-bit)/cpus=8,threads=1,free=67096344,total=232914944
   [junit4]   2> NOTE: All tests run in this JVM: [TestIBSimilarityFactory, DistanceFunctionTest, SignatureUpdateProcessorFactoryTest, TimeZoneUtilsTest, AlternateDirectoryTest, XmlUpdateRequestHandlerTest, TestRandomMergePolicy, TermVectorComponentDistributedTest, NotRequiredUniqueKeyTest, TestQuerySenderListener, TestWordDelimiterFilterFactory, TestManagedSchemaFieldResource, TestDFRSimilarityFactory, SimplePostToolTest, ZkNodePropsTest, PluginInfoTest, TestJmxIntegration, TestCursorMarkWithoutUniqueKey, TestCollationField, TestSolrQueryParserResource, ConvertedLegacyTest, PingRequestHandlerTest, TestBinaryField, TestReload, TestFastWriter, RequestHandlersTest, TestInitQParser, DistributedQueryComponentCustomSortTest, TestQueryTypes, IndexBasedSpellCheckerTest, HdfsChaosMonkeySafeLeaderTest, InfoHandlerTest, ConnectionManagerTest, TestCoreDiscovery, XsltUpdateRequestHandlerTest, TestSolrJ, RemoteQueryErrorTest, BadIndexSchemaTest, TestArbitraryIndexDir, TestIndexSearcher, LeaderElectionIntegrationTest, SpellCheckCollatorTest, StatsComponentTest, TestNonDefinedSimilarityFactory, SolrCoreCheckLockOnStartupTest, TestQuerySenderNoQuery, TestFastLRUCache, EnumFieldTest, DirectSolrConnectionTest, BlockCacheTest, TestFoldingMultitermQuery, OpenExchangeRatesOrgProviderTest, OutputWriterTest, TestClassNameShortening, DisMaxRequestHandlerTest, HdfsSyncSliceTest, TestCloudManagedSchemaAddField, DistributedExpandComponentTest, TestDefaultSimilarityFactory, TestNoOpRegenerator, SpellingQueryConverterTest, NumericFieldsTest, DefaultValueUpdateProcessorTest, CoreContainerCoreInitFailuresTest, TestAnalyzedSuggestions, BasicDistributedZk2Test, BasicZkTest, TestSolrXmlPersistor, FieldAnalysisRequestHandlerTest, TestUpdate, RequiredFieldsTest, SortByFunctionTest, MultiTermTest, SolrPluginUtilsTest, TestFastOutputStream, TestStressReorder, ChaosMonkeySafeLeaderTest, PreAnalyzedFieldTest, TestManagedSchema, MigrateRouteKeyTest, TestAtomicUpdateErrorCases, SolrIndexConfigTest, TestRTGBase, TestDynamicFieldResource, TestIndexingPerformance, DateFieldTest, HighlighterTest, TestDistributedSearch, TestHighFrequencyDictionaryFactory, BasicDistributedZkTest, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest, OpenCloseCoreStressTest, ShardRoutingTest, RecoveryZkTest, FullSolrCloudDistribCmdsTest, ClusterStateUpdateTest, TestRandomFaceting, ShardRoutingCustomTest, SliceStateUpdateTest, TestDistributedGrouping, TestFaceting, TestHashPartitioner, TestRealTimeGet, TestMultiCoreConfBootstrap, HardAutoCommitTest]
   [junit4] Completed on J1 in 5.12s, 1 test, 1 error <<< FAILURES!

[...truncated 493 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:471: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:464: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:490: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1278: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:911: There were test failures: 367 suites, 1575 tests, 1 error, 81 ignored (7 assumptions)

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



[JENKINS] Lucene-Solr-4.x-Linux (64bit/ibm-j9-jdk7) - Build # 9575 - Still Failing!

Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9575/
Java: 64bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}

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([EFEDE4A875BC7787:EBE56B5B671998A6]:0)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
	at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
	at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:666)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:613)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:780)
Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
	... 46 more
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
	at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:431)
	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:428)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:385)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:372)
	at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
	at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
	... 47 more




Build Log:
[...truncated 10287 lines...]
   [junit4] Suite: org.apache.solr.cloud.OverseerTest
   [junit4]   2> 141784 T464 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
   [junit4]   2> 141784 T464 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-OverseerTest-1394008980602
   [junit4]   2> 141785 T464 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 141792 T464 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
   [junit4]   2> 141792 T464 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 141793 T465 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 141893 T464 oasc.ZkTestServer.run start zk server on port:44894
   [junit4]   2> 141899 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 141974 T471 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@307533b5 name:ZooKeeperConnection Watcher:127.0.0.1:44894 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 141975 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 141979 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 141980 T473 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e2de815 name:ZooKeeperConnection Watcher:127.0.0.1:44894 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 141980 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 141981 T464 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 141986 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 141988 T475 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b305ce8 name:ZooKeeperConnection Watcher:127.0.0.1:44894/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 141988 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 141988 T464 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 141992 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 141993 T477 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@49549f2e name:ZooKeeperConnection Watcher:127.0.0.1:44894/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 141993 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 141998 T464 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 142001 T464 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 142011 T464 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:44894_solr
   [junit4]   2> 142011 T464 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 142017 T464 oasc.Overseer.start Overseer (id=91357772553715715-127.0.0.1:44894_solr-n_0000000000) starting
   [junit4]   2> 142031 T464 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 142038 T464 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 142055 T464 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 142060 T479 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 142061 T464 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 142062 T479 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 142063 T478 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 142066 T464 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 142069 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 142079 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 142082 T481 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2b8f3eb5 name:ZooKeeperConnection Watcher:127.0.0.1:44894/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 142083 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 142086 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 142089 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
   [junit4]   2> 142092 T475 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 142092 T481 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 142094 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 142096 T478 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 142097 T478 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 142097 T478 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 142099 T478 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 142102 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 142104 T481 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> 142104 T475 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> 142595 T464 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 142612 T464 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 142617 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 142618 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 142618 T478 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 142623 T478 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core2",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 142623 T478 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 142624 T478 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 142626 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 142730 T481 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> 142730 T475 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> 143119 T464 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 143130 T464 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 143136 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 143137 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 143137 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 143138 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 143138 T478 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 143141 T478 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core3",
   [junit4]   2> 	  "core_node_name":"node3",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 143142 T478 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 143142 T478 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 143144 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 143246 T475 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> 143246 T481 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> 143638 T464 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 143649 T464 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 143653 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 143653 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 143654 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 143655 T478 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 143658 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 143761 T481 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> 143761 T475 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> 143806 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 143806 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 143807 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 143808 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 143809 T478 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 143810 T478 oasc.Overseer$ClusterStateUpdater.checkCollection ERROR Skipping invalid Overseer message because it has no collection specified: {
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core0",
   [junit4]   2> 	  "core_node_name":"node0",
   [junit4]   2> 	  "collection":"",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 143810 T478 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core0",
   [junit4]   2> 	  "core_node_name":"node0",
   [junit4]   2> 	  "collection":"",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 143810 T478 oasc.Overseer$ClusterStateUpdater.createCollection Create collection  with shards [shard1]
   [junit4]   2> 143810 T478 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 143813 T478 oasc.Overseer$ClusterStateUpdater.checkCollection ERROR Skipping invalid Overseer message because it has no collection specified: {
   [junit4]   2> 	  "operation":"deletecore",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core0",
   [junit4]   2> 	  "core_node_name":"node0",
   [junit4]   2> 	  "collection":""}
   [junit4]   2> 143814 T478 oasc.Overseer$ClusterStateUpdater.run ERROR Could not process Overseer message java.lang.IllegalArgumentException: Path must not end with / character
   [junit4]   2> 	at org.apache.zookeeper.common.PathUtils.validatePath(PathUtils.java:58)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1450)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [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:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:620)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:977)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:253)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:202)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:780)
   [junit4]   2> 
   [junit4]   2> 143816 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 143817 T478 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"node1",
   [junit4]   2> 	  "collection":"collection2",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 143817 T478 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
   [junit4]   2> 143817 T478 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 143819 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 143922 T481 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> 143922 T475 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> 144310 T464 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
   [junit4]   2> 144319 T464 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
   [junit4]   2> 144323 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 144323 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 144324 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 144325 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 144325 T478 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 144328 T478 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core2",
   [junit4]   2> 	  "core_node_name":"node2",
   [junit4]   2> 	  "collection":"collection2",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 144328 T478 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 144329 T478 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 144331 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 144433 T475 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> 144433 T481 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> 144825 T464 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
   [junit4]   2> 144834 T464 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
   [junit4]   2> 144839 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 144839 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 144839 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 144841 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 144841 T478 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 144844 T478 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"127.0.0.1",
   [junit4]   2> 	  "core":"core3",
   [junit4]   2> 	  "core_node_name":"node3",
   [junit4]   2> 	  "collection":"collection2",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "base_url":"http://127.0.0.1/solr/"}
   [junit4]   2> 144845 T478 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 144845 T478 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 144847 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 144949 T475 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> 144949 T481 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> 145341 T464 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
   [junit4]   2> 145357 T464 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
   [junit4]   2> 145367 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 145367 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 145368 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 145370 T478 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 145376 T477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 145480 T481 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> 145480 T475 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> 145519 T481 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 145521 T464 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:44894 44894
   [junit4]   2> 145773 T464 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 145777 T464 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignmentBigger
   [junit4]   2> 145778 T464 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 145778 T482 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 145878 T464 oasc.ZkTestServer.run start zk server on port:46156
   [junit4]   2> 145880 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 145883 T488 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d747507e name:ZooKeeperConnection Watcher:127.0.0.1:46156 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 145883 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 145910 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 145912 T490 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ab4e34e0 name:ZooKeeperConnection Watcher:127.0.0.1:46156 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 145912 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 145912 T464 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 145918 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 145919 T492 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@834ca9de name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 145919 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 145919 T464 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 145923 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 145924 T494 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8442b3dc name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 145924 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 145925 T464 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 145927 T464 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 145931 T464 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:46156_solr
   [junit4]   2> 145931 T464 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 145933 T464 oasc.Overseer.start Overseer (id=91357772815073283-127.0.0.1:46156_solr-n_0000000000) starting
   [junit4]   2> 145935 T464 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 145937 T464 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 145941 T464 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 145943 T496 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 145944 T464 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 145944 T495 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 145944 T496 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 145947 T464 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 145949 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 145952 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 145954 T498 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6658019f name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 145954 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 145955 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 145958 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node0
   [junit4]   2> 145960 T492 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 145960 T498 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 145962 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 145963 T500 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@875251f1 name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 145963 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 145964 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 145966 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 145968 T492 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 145969 T498 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 145969 T500 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 145971 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 145972 T502 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10976c4c name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 145972 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 145973 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 145975 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 145977 T492 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 145977 T500 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 145978 T498 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 145978 T502 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 145980 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 145982 T504 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d9f218b0 name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 145982 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 145983 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 145985 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node3
   [junit4]   2> 145988 T492 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 145989 T504 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 145989 T502 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 145989 T500 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 145991 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 145996 T498 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 145997 T506 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@eda55f9c name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 145997 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 145998 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146002 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node4
   [junit4]   2> 146005 T492 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 146005 T500 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 146005 T498 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 146007 T506 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 146007 T502 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 146007 T504 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 146008 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146010 T508 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c10944a name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146010 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146011 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146014 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node5
   [junit4]   2> 146016 T500 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 146017 T492 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 146017 T498 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 146017 T502 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 146018 T506 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 146019 T504 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 146021 T508 oascc.ZkStateReader$3.process Updating live nodes... (6)
   [junit4]   2> 146021 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146023 T510 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2996a158 name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146023 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146024 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146027 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node6
   [junit4]   2> 146031 T500 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 146031 T502 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 146031 T508 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 146032 T504 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 146032 T492 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 146033 T498 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 146033 T506 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 146034 T510 oascc.ZkStateReader$3.process Updating live nodes... (7)
   [junit4]   2> 146036 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146038 T512 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@db96cdc9 name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146039 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146040 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146043 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node7
   [junit4]   2> 146047 T500 oascc.ZkStateReader$3.process Updating live nodes... (8)
   [junit4]   2> 146048 T498 oascc.ZkStateReader$3.process Updating live nodes... (8)
   [junit4]   2> 146048 T502 oascc.ZkStateReader$3.process Updating live nodes... (8)
   [junit4]   2> 146048 T504 oascc.ZkStateReader$3.process Updating live nodes... (8)
   [junit4]   2> 146049 T506 oascc.ZkStateReader$3.process Updating live nodes... (8)
   [junit4]   2> 146049 T508 oascc.ZkStateReader$3.process Updating live nodes... (8)
   [junit4]   2> 146049 T510 oascc.ZkStateReader$3.process Updating live nodes... (8)
   [junit4]   2> 146050 T512 oascc.ZkStateReader$3.process Updating live nodes... (8)
   [junit4]   2> 146050 T492 oascc.ZkStateReader$3.process Updating live nodes... (8)
   [junit4]   2> 146053 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146055 T514 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e04d7edd name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146055 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146057 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146059 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node8
   [junit4]   2> 146063 T508 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 146063 T492 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 146063 T504 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 146063 T512 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 146063 T498 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 146063 T502 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 146064 T514 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 146063 T500 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 146064 T510 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 146064 T506 oascc.ZkStateReader$3.process Updating live nodes... (9)
   [junit4]   2> 146068 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146069 T516 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7cae6dba name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146070 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146071 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146074 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node9
   [junit4]   2> 146078 T510 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 146080 T512 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 146080 T502 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 146078 T504 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 146080 T498 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 146080 T500 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 146080 T508 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 146080 T492 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 146080 T506 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 146080 T514 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 146082 T516 oascc.ZkStateReader$3.process Updating live nodes... (10)
   [junit4]   2> 146085 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146087 T518 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@533730ba name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146087 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146089 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146091 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node10
   [junit4]   2> 146097 T504 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 146097 T514 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 146097 T508 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 146097 T502 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 146097 T510 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 146098 T492 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 146098 T516 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 146100 T518 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 146099 T506 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 146099 T512 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 146099 T498 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 146099 T500 oascc.ZkStateReader$3.process Updating live nodes... (11)
   [junit4]   2> 146104 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146106 T520 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@53548899 name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146107 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146108 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146110 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node11
   [junit4]   2> 146114 T502 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 146114 T504 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 146114 T512 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 146114 T510 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 146114 T516 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 146115 T492 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 146116 T500 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 146115 T498 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 146115 T514 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 146115 T508 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 146114 T506 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 146117 T520 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 146118 T518 oascc.ZkStateReader$3.process Updating live nodes... (12)
   [junit4]   2> 146120 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146122 T522 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d14670cd name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146122 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146123 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146125 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node12
   [junit4]   2> 146128 T508 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 146128 T506 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 146129 T510 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 146128 T502 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 146129 T500 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 146129 T504 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 146130 T518 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 146130 T492 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 146129 T498 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 146130 T514 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 146132 T516 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 146129 T520 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 146129 T512 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 146130 T522 oascc.ZkStateReader$3.process Updating live nodes... (13)
   [junit4]   2> 146134 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146135 T524 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ce37f5e name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146136 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146137 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146139 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node13
   [junit4]   2> 146144 T502 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 146144 T508 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 146144 T498 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 146144 T514 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 146144 T518 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 146145 T520 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 146145 T516 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 146145 T510 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 146144 T512 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 146146 T504 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 146144 T506 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 146147 T492 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 146147 T522 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 146148 T524 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 146146 T500 oascc.ZkStateReader$3.process Updating live nodes... (14)
   [junit4]   2> 146150 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146152 T526 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5496ccd3 name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146153 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146154 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146157 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node14
   [junit4]   2> 146160 T492 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 146160 T518 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 146161 T502 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 146161 T510 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 146160 T504 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 146162 T520 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 146160 T508 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 146162 T522 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 146162 T524 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 146162 T512 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 146161 T498 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 146162 T514 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 146160 T506 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 146161 T500 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 146165 T526 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 146165 T516 oascc.ZkStateReader$3.process Updating live nodes... (15)
   [junit4]   2> 146167 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146168 T528 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@acc5a736 name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146169 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146170 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146173 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node15
   [junit4]   2> 146177 T518 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 146178 T520 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 146177 T510 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 146178 T512 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 146178 T506 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 146179 T508 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 146179 T498 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 146179 T514 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 146179 T504 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 146180 T524 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 146177 T502 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 146181 T500 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 146179 T522 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 146180 T492 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 146181 T526 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 146182 T528 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 146183 T516 oascc.ZkStateReader$3.process Updating live nodes... (16)
   [junit4]   2> 146185 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146187 T530 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50a2fd36 name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146188 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146189 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146192 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node16
   [junit4]   2> 146195 T518 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 146196 T502 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 146196 T512 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 146196 T508 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 146195 T524 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 146197 T504 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 146197 T510 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 146197 T520 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 146197 T500 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 146197 T528 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 146198 T492 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 146197 T514 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 146197 T506 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 146198 T522 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 146200 T526 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 146200 T530 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 146201 T516 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 146198 T498 oascc.ZkStateReader$3.process Updating live nodes... (17)
   [junit4]   2> 146203 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146205 T532 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ff18324f name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146206 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146207 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146210 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node17
   [junit4]   2> 146213 T506 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146214 T504 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146214 T530 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146214 T502 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146215 T520 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146215 T518 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146214 T514 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146215 T524 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146215 T492 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146219 T508 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146216 T500 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146216 T528 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146215 T498 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146220 T522 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146221 T510 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146215 T512 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146221 T526 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146223 T532 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146223 T516 oascc.ZkStateReader$3.process Updating live nodes... (18)
   [junit4]   2> 146226 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146227 T534 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6bbbaac6 name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146228 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146229 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146233 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node18
   [junit4]   2> 146237 T510 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146237 T500 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146237 T524 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146238 T498 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146238 T522 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146238 T528 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146239 T504 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146239 T520 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146238 T532 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146237 T502 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146239 T530 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146237 T506 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146237 T492 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146241 T526 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146237 T512 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146242 T508 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146242 T534 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146238 T514 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146239 T518 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146244 T516 oascc.ZkStateReader$3.process Updating live nodes... (19)
   [junit4]   2> 146245 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146248 T536 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@161f448d name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146248 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146250 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146252 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node19
   [junit4]   2> 146257 T532 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146257 T502 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146257 T530 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146257 T512 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146257 T510 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146257 T518 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146258 T520 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146259 T508 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146260 T522 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146260 T506 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146260 T504 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146260 T528 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146261 T526 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146261 T516 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146261 T500 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146261 T524 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146261 T492 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146260 T498 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146261 T514 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146263 T536 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146266 T534 oascc.ZkStateReader$3.process Updating live nodes... (20)
   [junit4]   2> 146266 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146268 T538 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@dd722a78 name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146268 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146269 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146272 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node20
   [junit4]   2> 146278 T532 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146278 T518 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146278 T530 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146278 T516 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146278 T502 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146279 T520 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146278 T506 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146280 T510 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146279 T508 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146280 T522 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146280 T528 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146281 T514 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146278 T512 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146281 T492 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146282 T538 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146281 T524 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146282 T526 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146281 T504 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146283 T500 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146279 T498 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146283 T534 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146284 T536 oascc.ZkStateReader$3.process Updating live nodes... (21)
   [junit4]   2> 146286 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146288 T540 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5dfdd24e name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146289 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146290 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146293 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node21
   [junit4]   2> 146301 T532 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146302 T514 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146302 T516 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146302 T530 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146303 T522 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146303 T500 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146303 T534 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146303 T502 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146303 T512 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146303 T520 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146302 T538 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146303 T510 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146302 T508 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146302 T506 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146303 T492 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146303 T536 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146309 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146302 T528 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146311 T542 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@45b22d44 name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146309 T540 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146312 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146303 T526 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146302 T504 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146303 T524 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146314 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146303 T498 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146303 T518 oascc.ZkStateReader$3.process Updating live nodes... (22)
   [junit4]   2> 146317 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node22
   [junit4]   2> 146321 T532 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146322 T516 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146322 T510 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146322 T524 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146322 T538 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146323 T498 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146322 T528 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146323 T506 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146321 T520 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146323 T500 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146322 T512 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146325 T518 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146321 T522 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146326 T540 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146325 T534 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146322 T530 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146326 T492 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146323 T526 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146323 T514 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146328 T508 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146329 T536 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146322 T504 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146329 T542 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146323 T502 oascc.ZkStateReader$3.process Updating live nodes... (23)
   [junit4]   2> 146332 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146333 T544 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f4c7395f name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146334 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146335 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146337 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node23
   [junit4]   2> 146341 T502 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146341 T530 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146342 T504 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146342 T540 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146342 T522 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146342 T532 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146341 T538 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146342 T516 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146343 T518 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146343 T498 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146344 T534 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146342 T524 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146345 T492 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146341 T512 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146342 T510 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146346 T536 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146344 T500 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146345 T542 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146344 T506 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146342 T514 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146348 T526 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146348 T544 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146344 T508 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146342 T520 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146342 T528 oascc.ZkStateReader$3.process Updating live nodes... (24)
   [junit4]   2> 146351 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146354 T546 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@eebdeb16 name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146354 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146356 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146358 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node24
   [junit4]   2> 146364 T540 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146365 T544 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146365 T520 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146365 T510 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146364 T530 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146365 T502 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146364 T532 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146367 T500 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146367 T492 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146367 T512 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146365 T508 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146367 T524 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146367 T514 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146367 T538 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146370 T506 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146369 T536 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146374 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146371 T534 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146370 T528 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146370 T516 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146372 T546 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146370 T518 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146371 T504 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146373 T498 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146371 T526 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146371 T542 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146376 T548 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f16ce755 name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146370 T522 oascc.ZkStateReader$3.process Updating live nodes... (25)
   [junit4]   2> 146379 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146381 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146383 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node25
   [junit4]   2> 146392 T540 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146392 T532 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146392 T530 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146393 T514 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146393 T492 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146394 T520 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146394 T524 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146394 T538 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146395 T544 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146395 T536 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146395 T510 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146395 T512 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146395 T502 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146397 T508 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146397 T500 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146397 T516 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146398 T546 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146398 T498 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146398 T518 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146400 T506 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146400 T522 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146401 T504 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146401 T526 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146401 T528 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146401 T548 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146401 T534 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146401 T542 oascc.ZkStateReader$3.process Updating live nodes... (26)
   [junit4]   2> 146405 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146407 T550 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@89c004d5 name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146408 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146409 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146412 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node26
   [junit4]   2> 146416 T518 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146416 T512 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146417 T540 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146416 T538 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146417 T542 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146417 T522 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146417 T504 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146418 T548 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146418 T508 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146418 T492 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146417 T498 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146417 T530 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146418 T502 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146420 T514 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146417 T500 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146418 T528 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146418 T506 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146422 T544 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146422 T532 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146423 T510 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146423 T520 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146423 T526 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146423 T524 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146424 T534 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146424 T546 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146423 T516 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146424 T536 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146424 T550 oascc.ZkStateReader$3.process Updating live nodes... (27)
   [junit4]   2> 146427 T464 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 146428 T552 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@322c52ca name:ZooKeeperConnection Watcher:127.0.0.1:46156/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 146428 T464 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 146430 T464 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 146433 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node27
   [junit4]   2> 146437 T516 oascc.ZkStateReader$3.process Updating live nodes... (28)
   [junit4]   2> 146437 T510 oascc.ZkStateReader$3.process Updating live nodes... (28)
   [junit4]   2> 146438 T530 oascc.ZkStateReader$3.process Updating live nodes... (28)
   [junit4]   2> 146438 T518 oascc.ZkStateReader$3.process Updating live nodes... (28)
   [junit4]   2> 146438 T502 oascc.ZkStateReader$3.process Updating live nodes... (28)
   [junit4]   2> 146439 T522 oascc.ZkStateReader$3.process Updating live nodes... (28)
   [junit4]   2> 146439 T512 oascc.ZkStateReader$3.process Updating live nodes... (28)
   [junit4]   2> 146439 T526 oascc.ZkStateReader$3.process Updating live nodes... (28)
   [junit4]   2> 146439 T538 oascc.ZkStateReader$3.process Updating live nodes... (28)
   [junit4]   2> 146440 T528 oascc.ZkStateReader$3.process Updating live nodes... (28)
   [junit4]   2> 146439 T536 oascc.ZkStateReader$3.process Updating live nodes... (28)
   [junit4]   2> 146440 T532 oascc.ZkStateReader$3.process Updating live nodes... (28)
   [junit4]   2> 146439 T540 oascc.ZkStateReader$3.process Updating live nodes... (28)
   [junit4]   2> 146440 T548 oascc.ZkStateReader$3.process Updating live nodes... (28)
   [junit4]   2> 146438 T492 oascc.ZkStateReader$3.process Updating live nodes... (28)
   [junit4]   2> 146442 T514 oascc.ZkStateReader$3.

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

er.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 192324 T464 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 192325 T1029 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 192325 T1041 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 192327 T1037 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 192327 T464 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 192328 T1038 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> 192328 T1038 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 192330 T1037 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 192335 T464 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 192338 T1037 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 192341 T1037 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 192443 T1041 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> 192444 T1029 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> 192446 T464 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 192449 T1029 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 192449 T1041 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 192451 T464 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55952 55952
   [junit4]   2> 192641 T464 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 192645 T464 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 192645 T464 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 193059 T1022 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [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:256)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 193059 T1022 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [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:256)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 193060 T1022 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [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:256)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 193816 T1035 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 195646 T464 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene42, sim=DefaultSimilarity, locale=fr_LU, timezone=Etc/GMT-14
   [junit4]   2> NOTE: Linux 3.8.0-36-generic amd64/IBM Corporation 1.7.0 (64-bit)/cpus=8,threads=1,free=83384872,total=152633344
   [junit4]   2> NOTE: All tests run in this JVM: [TestSimpleQParserPlugin, SOLR749Test, TestCharFilters, ZkCLITest, SampleTest, TestSchemaNameResource, TestDefaultSearchFieldResource, TestCollationKeyRangeQueries, TestSystemIdResolver, LoggingHandlerTest, BadComponentTest, TestGroupingSearch, ResourceLoaderTest, TestUniqueKeyFieldResource, DistributedSpellCheckComponentTest, TestDistribDocBasedVersion, TestWriterPerf, CSVRequestHandlerTest, DistributedTermsComponentTest, TestPseudoReturnFields, PreAnalyzedUpdateProcessorTest, DistributedQueryComponentOptimizationTest, TestAddFieldRealTimeGet, TestCopyFieldCollectionResource, UpdateParamsTest, LegacyHTMLStripCharFilterTest, TestTrie, TestNonNRTOpen, QueryEqualityTest, HdfsCollectionsAPIDistributedZkTest, SoftAutoCommitTest, SimpleFacetsTest, TestMaxScoreQueryParser, PolyFieldTest, TestLMDirichletSimilarityFactory, TestNRTOpen, SchemaVersionSpecificBehaviorTest, CursorMarkTest, FieldMutatingUpdateProcessorTest, ClusterStateTest, SearchHandlerTest, ChangedSchemaMergeTest, SuggesterFSTTest, JsonLoaderTest, OverseerTest]
   [junit4] Completed on J0 in 53.89s, 9 tests, 1 error <<< FAILURES!

[...truncated 868 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:471: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:464: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:490: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1278: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:911: There were test failures: 367 suites, 1575 tests, 1 error, 81 ignored (7 assumptions)

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