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/22 22:03:26 UTC
[JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.7.0_60-ea-b10) -
Build # 9877 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9877/
Java: 64bit/jdk1.7.0_60-ea-b10 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed.
REGRESSION: org.apache.solr.morphlines.cell.SolrCellMorphlineTest.testSolrCellDocumentTypes
Error Message:
key:ignored__attachment_mimetype expected:<[message/rfc822]> but was:<[text/plain]>
Stack Trace:
java.lang.AssertionError: key:ignored__attachment_mimetype expected:<[message/rfc822]> but was:<[text/plain]>
at __randomizedtesting.SeedInfo.seed([CE2FA82663A7CE5F:54EC0BB8067C908A]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.apache.solr.morphlines.solr.AbstractSolrMorphlineTestBase.testDocumentTypesInternal(AbstractSolrMorphlineTestBase.java:171)
at org.apache.solr.morphlines.cell.SolrCellMorphlineTest.testSolrCellDocumentTypes(SolrCellMorphlineTest.java:193)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1617)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at java.lang.Thread.run(Thread.java:744)
Build Log:
[...truncated 18422 lines...]
[junit4] Suite: org.apache.solr.morphlines.cell.SolrCellMorphlineTest
[junit4] 2> log4j:WARN No such property [conversionPattern] in org.apache.solr.util.SolrLogLayout.
[junit4] 2> 725 T11 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 757 T11 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-morphlines-cell/test/J0/./solrtest-SolrCellMorphlineTest-1395522174258
[junit4] 2> 791 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/'
[junit4] 2> 1380 T11 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 1382 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/extraction/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/extraction/lib).
[junit4] 2> 1383 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 1383 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/clustering/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/clustering/lib).
[junit4] 2> 1384 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 1385 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/langid/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/langid/lib).
[junit4] 2> 1385 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 1386 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/velocity/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/velocity/lib).
[junit4] 2> 1387 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 1387 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: /non/existent/dir/yields/warning (resolved as: /non/existent/dir/yields/warning).
[junit4] 2> 1551 T11 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4] 2> 1774 T11 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1782 T11 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1892 T11 oass.IndexSchema.readSchema [null] Schema name=example
[junit4] 2> 2622 T11 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [solr.ThaiWordFilterFactory]. Please consult documentation how to replace it accordingly.
[junit4] 2> 2664 T11 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2841 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2853 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 3003 T11 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 3004 T11 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr
[junit4] 2> 3005 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/'
[junit4] 2> 3131 T11 oasc.CoreContainer.<init> New CoreContainer 1581263530
[junit4] 2> 3132 T11 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/]
[junit4] 2> 3151 T11 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 3152 T11 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
[junit4] 2> 3159 T11 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 3159 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 3160 T11 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 3161 T11 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 3161 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 3162 T11 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 3162 T11 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 3370 T11 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 3372 T11 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 3374 T11 oasc.CoreContainer.load Host Name:
[junit4] 2> 3468 T12 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1
[junit4] 2> 3469 T12 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/'
[junit4] 2> 3557 T12 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 3558 T12 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/extraction/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/extraction/lib).
[junit4] 2> 3559 T12 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 3560 T12 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/clustering/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/clustering/lib).
[junit4] 2> 3560 T12 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 3561 T12 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/langid/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/langid/lib).
[junit4] 2> 3561 T12 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 3562 T12 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/velocity/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/velocity/lib).
[junit4] 2> 3563 T12 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 3563 T12 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: /non/existent/dir/yields/warning (resolved as: /non/existent/dir/yields/warning).
[junit4] 2> 3627 T12 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4] 2> 3715 T12 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 3716 T12 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 3780 T12 oass.IndexSchema.readSchema [collection1] Schema name=example
[junit4] 2> 4231 T12 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 4263 T12 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 4271 T12 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 4385 T12 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 4396 T12 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-morphlines-cell/test/J0/./solrtest-SolrCellMorphlineTest-1395522174258/
[junit4] 2> 4399 T12 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
[junit4] 2> 4414 T12 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4] 2> 4415 T12 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
[junit4] 2> 4453 T12 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-morphlines-cell/test/J0/./solrtest-SolrCellMorphlineTest-1395522174258
[junit4] 2> 4454 T12 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-morphlines-cell/test/J0/./solrtest-SolrCellMorphlineTest-1395522174258/index/
[junit4] 2> 4455 T12 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-morphlines-cell/test/J0/./solrtest-SolrCellMorphlineTest-1395522174258/index' doesn't exist. Creating new index...
[junit4] 2> 4465 T12 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-morphlines-cell/test/J0/./solrtest-SolrCellMorphlineTest-1395522174258/index
[junit4] 2> 4522 T12 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@137a151c lockFactory=NativeFSLockFactory@/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-morphlines-cell/test/J0/./solrtest-SolrCellMorphlineTest-1395522174258/index),segFN=segments_1,generation=1}
[junit4] 2> 4524 T12 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 4536 T12 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 4537 T12 oasc.SolrCore.initWriters adding lazy queryResponseWriter: solr.VelocityResponseWriter
[junit4] 2> 4538 T12 oasc.SolrCore.initWriters created velocity: solr.VelocityResponseWriter
[junit4] 2> 4557 T12 oasc.SolrCore.initWriters created xslt: solr.XSLTResponseWriter
[junit4] 2> 4557 T12 oasr.XSLTResponseWriter.init xsltCacheLifetimeSeconds=5
[junit4] 2> 4849 T12 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 4878 T12 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 4879 T12 oasc.RequestHandlers.initHandlersFromConfig created /query: solr.SearchHandler
[junit4] 2> 4885 T12 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 4886 T12 oasc.RequestHandlers.initHandlersFromConfig created /browse: solr.SearchHandler
[junit4] 2> 4893 T12 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 4898 T12 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [solr.JsonUpdateRequestHandler]. Please consult documentation how to replace it accordingly.
[junit4] 2> 4899 T12 oasc.RequestHandlers.initHandlersFromConfig created /update/json: solr.JsonUpdateRequestHandler
[junit4] 2> 4904 T12 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [solr.CSVRequestHandler]. Please consult documentation how to replace it accordingly.
[junit4] 2> 4904 T12 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: solr.CSVRequestHandler
[junit4] 2> 4905 T12 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.FieldAnalysisRequestHandler
[junit4] 2> 4906 T12 oasc.RequestHandlers.initHandlersFromConfig created /analysis/field: solr.FieldAnalysisRequestHandler
[junit4] 2> 4906 T12 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
[junit4] 2> 4907 T12 oasc.RequestHandlers.initHandlersFromConfig created /analysis/document: solr.DocumentAnalysisRequestHandler
[junit4] 2> 4913 T12 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 4918 T12 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
[junit4] 2> 4923 T12 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 4937 T12 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 4938 T12 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 4938 T12 oasc.RequestHandlers.initHandlersFromConfig created /spell: solr.SearchHandler
[junit4] 2> 4938 T12 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 4939 T12 oasc.RequestHandlers.initHandlersFromConfig created /tvrh: solr.SearchHandler
[junit4] 2> 4939 T12 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 4940 T12 oasc.RequestHandlers.initHandlersFromConfig created /terms: solr.SearchHandler
[junit4] 2> 4940 T12 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 4940 T12 oasc.RequestHandlers.initHandlersFromConfig created /elevate: solr.SearchHandler
[junit4] 2> 4977 T12 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 4982 T12 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 4983 T12 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 5009 T12 oasu.CommitTracker.<init> Hard AutoCommit: if uncommited for 60000ms;
[junit4] 2> 5009 T12 oasu.CommitTracker.<init> Soft AutoCommit: if uncommited for 1000ms;
[junit4] 2> 5011 T12 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@137a151c lockFactory=NativeFSLockFactory@/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-morphlines-cell/test/J0/./solrtest-SolrCellMorphlineTest-1395522174258/index),segFN=segments_1,generation=1}
[junit4] 2> 5012 T12 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 5024 T12 oass.SolrIndexSearcher.<init> Opening Searcher@395e81c0[collection1] main
[junit4] 2> 5037 T12 oasr.ManagedResourceStorage$FileStorageIO.configure File-based storage initialized to use dir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/conf
[junit4] 2> 5038 T12 oasr.RestManager.init Initializing RestManager with initArgs: {storageDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/conf/}
[junit4] 2> 5057 T12 oasr.ManagedResourceStorage.load Reading _rest_managed.json using file:dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/conf
[junit4] 2> 5058 T12 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 5058 T12 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 5058 T12 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 5059 T12 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 5077 T12 oass.DirectSolrSpellChecker.init init: {name=default,field=name,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
[junit4] 2> 5095 T12 oashc.SpellCheckComponent.inform No queryConverter defined, using default converter
[junit4] 2> 5099 T12 oashc.QueryElevationComponent.inform Loading QueryElevation from: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/conf/elevate.xml
[junit4] 2> 5169 T12 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 5170 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@395e81c0[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 5171 T12 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 5179 T11 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 5215 T11 oas.SolrTestCaseJ4.setUp ###Starting testSolrCellDocumentTypes
[junit4] 2> ASYNC NEW_CORE C0 name=collection1 org.apache.solr.core.SolrCore@3899abfc
[junit4] 2> 5264 T13 C0 oasc.SolrCore.execute [collection1] webapp=null path=null params={event=firstSearcher&distrib=false&q=static+firstSearcher+warming+in+solrconfig.xml} hits=0 status=0 QTime=90
[junit4] 2> 5266 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 5267 T13 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
[junit4] 2> 5267 T13 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
[junit4] 2> 5268 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@395e81c0[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> ASYNC NEW_CORE C1 name=collection1 org.apache.solr.core.SolrCore@3899abfc
[junit4] 2> 5379 T11 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {deleteByQuery=*:* (-1463311064181506048)} 0 148
[junit4] 2> 5382 T11 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 5382 T11 C1 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 5383 T11 C1 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
[junit4] 2> 5384 T11 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 5385 T11 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=false&waitSearcher=true} {commit=} 0 4
[junit4] 2> 5598 T11 okma.MorphlineContext.importCommandBuilders Importing commands
[junit4] 2> 6885 T11 okma.MorphlineContext.importCommandBuilders Done importing commands
[junit4] 2> 9029 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/'
[junit4] 2> 9083 T11 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 9085 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/extraction/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/extraction/lib).
[junit4] 2> 9087 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 9089 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/clustering/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/clustering/lib).
[junit4] 2> 9091 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 9093 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/langid/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/langid/lib).
[junit4] 2> 9096 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 9098 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/velocity/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/velocity/lib).
[junit4] 2> 9100 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 9102 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: /non/existent/dir/yields/warning (resolved as: /non/existent/dir/yields/warning).
[junit4] 2> 9140 T11 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4] 2> 9220 T11 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 9222 T11 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 9266 T11 oass.IndexSchema.readSchema [null] Schema name=example
[junit4] 2> 9691 T11 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 9718 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 9726 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 9794 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/'
[junit4] 2> 9848 T11 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 9849 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/extraction/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/extraction/lib).
[junit4] 2> 9850 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 9851 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/clustering/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/clustering/lib).
[junit4] 2> 9852 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 9853 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/langid/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/langid/lib).
[junit4] 2> 9854 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 9855 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/velocity/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/velocity/lib).
[junit4] 2> 9856 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 9857 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: /non/existent/dir/yields/warning (resolved as: /non/existent/dir/yields/warning).
[junit4] 2> 9896 T11 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4] 2> 9967 T11 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 9968 T11 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 10015 T11 oass.IndexSchema.readSchema [null] Schema name=example
[junit4] 2> 10415 T11 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 10449 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 10456 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 10978 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/'
[junit4] 2> 11017 T11 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 11018 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/extraction/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/extraction/lib).
[junit4] 2> 11018 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 11019 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/clustering/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/clustering/lib).
[junit4] 2> 11019 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 11020 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/langid/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/langid/lib).
[junit4] 2> 11020 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 11021 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/velocity/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/velocity/lib).
[junit4] 2> 11022 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 11022 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: /non/existent/dir/yields/warning (resolved as: /non/existent/dir/yields/warning).
[junit4] 2> 11059 T11 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4] 2> 11125 T11 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 11126 T11 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 11154 T11 oass.IndexSchema.readSchema [null] Schema name=example
[junit4] 2> 11558 T11 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 11580 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 11586 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 11620 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/'
[junit4] 2> 11658 T11 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 11659 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/extraction/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/extraction/lib).
[junit4] 2> 11659 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 11660 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/clustering/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/clustering/lib).
[junit4] 2> 11661 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 11661 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/langid/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/langid/lib).
[junit4] 2> 11662 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 11662 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/velocity/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/velocity/lib).
[junit4] 2> 11663 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 11663 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: /non/existent/dir/yields/warning (resolved as: /non/existent/dir/yields/warning).
[junit4] 2> 11699 T11 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4] 2> 11767 T11 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 11768 T11 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 11796 T11 oass.IndexSchema.readSchema [null] Schema name=example
[junit4] 2> 12218 T11 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 12247 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 12255 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 12485 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/'
[junit4] 2> 12530 T11 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 12530 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/extraction/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/extraction/lib).
[junit4] 2> 12531 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 12531 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/clustering/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/clustering/lib).
[junit4] 2> 12532 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 12533 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/langid/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/langid/lib).
[junit4] 2> 12533 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 12534 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/velocity/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/velocity/lib).
[junit4] 2> 12534 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 12535 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: /non/existent/dir/yields/warning (resolved as: /non/existent/dir/yields/warning).
[junit4] 2> 12574 T11 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4] 2> 12637 T11 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 12638 T11 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 12657 T11 oass.IndexSchema.readSchema [null] Schema name=example
[junit4] 2> 13019 T11 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 13040 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 13045 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> ASYNC NEW_CORE C2 name=collection1 org.apache.solr.core.SolrCore@3899abfc
[junit4] 2> 13072 T11 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {deleteByQuery=*:* (-1463311072306921472)} 0 1
[junit4] 2> 13073 T11 C2 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 13074 T11 C2 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 13074 T11 C2 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
[junit4] 2> 13075 T11 C2 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 13075 T11 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=false&waitSearcher=true} {commit=} 0 2
[junit4] 2> ASYNC NEW_CORE C3 name=collection1 org.apache.solr.core.SolrCore@3899abfc
[junit4] 2> 13423 T11 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[testBMPfp.txt#0 (1463311072620445696)]} 0 54
[junit4] 2> 13426 T11 C3 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 13505 T11 C3 oass.SolrIndexSearcher.<init> Opening Searcher@22058915[collection1] main
[junit4] 2> 13507 T11 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 13507 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@22058915[collection1] main{StandardDirectoryReader(segments_1:3:nrt _0(5.0):C1)}
[junit4] 2> 13508 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 13509 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@22058915[collection1] main{StandardDirectoryReader(segments_1:3:nrt _0(5.0):C1)}
[junit4] 2> 13510 T11 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 84
[junit4] 2> 13520 T11 C3 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=1 status=0 QTime=7
[junit4] 2> 13625 T11 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[boilerplate.html#0 (1463311072884686848)]} 0 4
[junit4] 2> 13626 T11 C3 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 13649 T11 C3 oass.SolrIndexSearcher.<init> Opening Searcher@d3f7d71[collection1] main
[junit4] 2> 13649 T11 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 13650 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@d3f7d71[collection1] main{StandardDirectoryReader(segments_1:5:nrt _0(5.0):C1 _1(5.0):C1)}
[junit4] 2> 13651 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 13652 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@d3f7d71[collection1] main{StandardDirectoryReader(segments_1:5:nrt _0(5.0):C1 _1(5.0):C1)}
[junit4] 2> 13653 T11 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 28
[junit4] 2> 13654 T11 C3 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=2 status=0 QTime=0
[junit4] 2> ASYNC NEW_CORE C4 name=collection1 org.apache.solr.core.SolrCore@3899abfc
[junit4] 2> 14772 T11 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[NullHeader.docx#0 (1463311074071674880)]} 0 20
[junit4] 2> 14773 T11 C4 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 14864 T11 C4 oass.SolrIndexSearcher.<init> Opening Searcher@726375bb[collection1] main
[junit4] 2> 14866 T11 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 14866 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@726375bb[collection1] main{StandardDirectoryReader(segments_1:7:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1)}
[junit4] 2> 14867 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 14867 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@726375bb[collection1] main{StandardDirectoryReader(segments_1:7:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1)}
[junit4] 2> 14868 T11 C4 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 95
[junit4] 2> 14869 T11 C4 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=3 status=0 QTime=0
[junit4] 2> ASYNC NEW_CORE C5 name=collection1 org.apache.solr.core.SolrCore@3899abfc
[junit4] 2> 15374 T11 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[testWORD_various.doc#0 (1463311074713403392)]} 0 10
[junit4] 2> 15375 T11 C5 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 15388 T11 C5 oass.SolrIndexSearcher.<init> Opening Searcher@6157aa06[collection1] main
[junit4] 2> 15389 T11 C5 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 15389 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@6157aa06[collection1] main{StandardDirectoryReader(segments_1:9:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1)}
[junit4] 2> 15390 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 15390 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6157aa06[collection1] main{StandardDirectoryReader(segments_1:9:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1)}
[junit4] 2> 15392 T11 C5 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 17
[junit4] 2> 15393 T11 C5 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=4 status=0 QTime=1
[junit4] 2> ASYNC NEW_CORE C6 name=collection1 org.apache.solr.core.SolrCore@3899abfc
[junit4] 2> 16266 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[testPDF.pdf#0 (1463311075648733184)]} 0 9
[junit4] 2> 16268 T11 C6 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 16283 T11 C6 oass.SolrIndexSearcher.<init> Opening Searcher@6a73a94d[collection1] main
[junit4] 2> 16285 T11 C6 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 16285 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@6a73a94d[collection1] main{StandardDirectoryReader(segments_1:11:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1 _4(5.0):C1)}
[junit4] 2> 16286 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 16286 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6a73a94d[collection1] main{StandardDirectoryReader(segments_1:11:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1 _4(5.0):C1)}
[junit4] 2> 16287 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 20
[junit4] 2> 16289 T11 C6 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=5 status=0 QTime=1
[junit4] 2> 16434 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[testJPEG_EXIF.jpg#0 (1463311075820699648)]} 0 16
[junit4] 2> 16435 T11 C6 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 16450 T11 C6 oass.SolrIndexSearcher.<init> Opening Searcher@7c5ce19d[collection1] main
[junit4] 2> 16451 T11 C6 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 16451 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@7c5ce19d[collection1] main{StandardDirectoryReader(segments_1:13:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1 _4(5.0):C1 _5(5.0):C1)}
[junit4] 2> 16452 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 16452 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7c5ce19d[collection1] main{StandardDirectoryReader(segments_1:13:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1 _4(5.0):C1 _5(5.0):C1)}
[junit4] 2> 16453 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 18
[junit4] 2> 16454 T11 C6 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=6 status=0 QTime=0
[junit4] 2> 16502 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[testJPEG_EXIF.jpg.gz#0 (1463311075892002816)]} 0 16
[junit4] 2> 16503 T11 C6 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 16519 T11 C6 oass.SolrIndexSearcher.<init> Opening Searcher@53063d6c[collection1] main
[junit4] 2> 16521 T11 C6 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 16521 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@53063d6c[collection1] main{StandardDirectoryReader(segments_1:15:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1 _4(5.0):C1 _5(5.0):C1 _6(5.0):C1)}
[junit4] 2> 16522 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 16522 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@53063d6c[collection1] main{StandardDirectoryReader(segments_1:15:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1 _4(5.0):C1 _5(5.0):C1 _6(5.0):C1)}
[junit4] 2> 16524 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 21
[junit4] 2> 16525 T11 C6 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=7 status=0 QTime=1
[junit4] 2> 16573 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[b102984f-916a-4780-b8eb-efca02e15526 (1463311075969597440)]} 0 16
[junit4] 2> 16574 T11 C6 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 16587 T11 C6 oass.SolrIndexSearcher.<init> Opening Searcher@3b9c66e2[collection1] main
[junit4] 2> 16588 T11 C6 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 16588 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@3b9c66e2[collection1] main{StandardDirectoryReader(segments_1:17:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1 _4(5.0):C1 _5(5.0):C1 _6(5.0):C1 _7(5.0):C1)}
[junit4] 2> 16589 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 16590 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3b9c66e2[collection1] main{StandardDirectoryReader(segments_1:17:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1 _4(5.0):C1 _5(5.0):C1 _6(5.0):C1 _7(5.0):C1)}
[junit4] 2> 16591 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 17
[junit4] 2> 16592 T11 C6 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=8 status=0 QTime=0
[junit4] 2> 16629 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[testXML.xml#0 (1463311076034609152)]} 0 4
[junit4] 2> 16630 T11 C6 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 16636 T11 C6 oass.SolrIndexSearcher.<init> Opening Searcher@55a3505e[collection1] main
[junit4] 2> 16637 T11 C6 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 16637 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@55a3505e[collection1] main{StandardDirectoryReader(segments_1:19:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1 _4(5.0):C1 _5(5.0):C1 _6(5.0):C1 _7(5.0):C1 _8(5.0):C1)}
[junit4] 2> 16638 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 16638 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@55a3505e[collection1] main{StandardDirectoryReader(segments_1:19:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1 _4(5.0):C1 _5(5.0):C1 _6(5.0):C1 _7(5.0):C1 _8(5.0):C1)}
[junit4] 2> 16639 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 9
[junit4] 2> 16640 T11 C6 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=9 status=0 QTime=0
[junit4] 2> 16649 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[e326ab31-7b2d-46a4-bcd1-b9cae379440f (1463311076057677824)]} 0 2
[junit4] 2> 16650 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[fe47e10a-6152-4bf2-aa9c-f82b015c3690 (1463311076059774976)]} 0 0
[junit4] 2> 16652 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[258b3a6e-3762-4fa2-8e72-b70679867596 (1463311076060823552)]} 0 1
[junit4] 2> 16654 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[bd59beab-0206-4ee4-a53c-7ebc778ed11f (1463311076062920704)]} 0 1
[junit4] 2> 16655 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[08050b37-94b0-4236-baaf-107ede51ce54 (1463311076065017856)]} 0 0
[junit4] 2> 16657 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[735784eb-f755-4a1d-a311-e370cdc4d21a (1463311076066066432)]} 0 1
[junit4] 2> 16658 T11 C6 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 16672 T11 C6 oass.SolrIndexSearcher.<init> Opening Searcher@4695220b[collection1] main
[junit4] 2> 16674 T11 C6 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 16674 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@4695220b[collection1] main{StandardDirectoryReader(segments_1:21:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1 _4(5.0):C1 _5(5.0):C1 _6(5.0):C1 _7(5.0):C1 _8(5.0):C1 _9(5.0):C6)}
[junit4] 2> 16675 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 16677 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4695220b[collection1] main{StandardDirectoryReader(segments_1:21:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1 _4(5.0):C1 _5(5.0):C1 _6(5.0):C1 _7(5.0):C1 _8(5.0):C1 _9(5.0):C6)}
[junit4] 2> 16680 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 22
[junit4] 2> 16682 T11 C6 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=15 status=0 QTime=1
[junit4] 2> 16699 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[9fd263c2-f2e9-45e7-a182-825e7c0e5227 (1463311076108009472)]} 0 3
[junit4] 2> 16702 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[29833738-335f-4643-95f1-7b8343e34fd7 (1463311076113252352)]} 0 1
[junit4] 2> 16704 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[ffe5e83e-16eb-46e6-808a-c79b21e7d550 (1463311076116398080)]} 0 1
[junit4] 2> 16706 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[587683a7-73a1-4771-8ea4-6b386d0c8597 (1463311076117446656)]} 0 1
[junit4] 2> 16707 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[041cf7fb-fcaa-4844-a0b5-790ced8f05fe (1463311076119543808)]} 0 0
[junit4] 2> 16709 T11 C6 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[e3dd53d0-2318-415d-b3b4-cb70924521a4 (1463311076121640960)]} 0 1
[junit4] 2> 16711 T11 C6 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> ASYNC NEW_CORE C7 name=collection1 org.apache.solr.core.SolrCore@3899abfc
[junit4] 2> 16731 T11 C7 oass.SolrIndexSearcher.<init> Opening Searcher@3c2686b8[collection1] main
[junit4] 2> 16732 T11 C7 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 16732 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@3c2686b8[collection1] main{StandardDirectoryReader(segments_1:24:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1 _4(5.0):C1 _5(5.0):C1 _6(5.0):C1 _7(5.0):C1 _8(5.0):C1 _9(5.0):C6 _b(5.0):C6)}
[junit4] 2> 16733 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 16734 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3c2686b8[collection1] main{StandardDirectoryReader(segments_1:24:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1 _4(5.0):C1 _5(5.0):C1 _6(5.0):C1 _7(5.0):C1 _8(5.0):C1 _9(5.0):C6 _b(5.0):C6)}
[junit4] 2> 16735 T11 C7 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 25
[junit4] 2> 16736 T11 C7 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=21 status=0 QTime=1
[junit4] 2> 16747 T11 C7 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[4032e929-7b1e-4332-8a29-6ba3c58fbb54 (1463311076160438272)]} 0 1
[junit4] 2> 16749 T11 C7 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[f7a28ad3-7040-4639-8913-d65c42c0e53c (1463311076162535424)]} 0 1
[junit4] 2> 16752 T11 C7 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[eb2829dc-1ba4-4fea-b312-6ec4cebf919d (1463311076166729728)]} 0 1
[junit4] 2> 16754 T11 C7 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[c94276b2-7e58-47af-aa92-3448f8d4657b (1463311076167778304)]} 0 1
[junit4] 2> 16755 T11 C7 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 16763 T11 C7 oass.SolrIndexSearcher.<init> Opening Searcher@3e4e3443[collection1] main
[junit4] 2> 16764 T11 C7 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 16764 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@3e4e3443[collection1] main{StandardDirectoryReader(segments_1:26:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1 _4(5.0):C1 _5(5.0):C1 _6(5.0):C1 _7(5.0):C1 _8(5.0):C1 _9(5.0):C6 _b(5.0):C6 _c(5.0):C4)}
[junit4] 2> 16764 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 16765 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3e4e3443[collection1] main{StandardDirectoryReader(segments_1:26:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1 _4(5.0):C1 _5(5.0):C1 _6(5.0):C1 _7(5.0):C1 _8(5.0):C1 _9(5.0):C6 _b(5.0):C6 _c(5.0):C4)}
[junit4] 2> 16766 T11 C7 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 11
[junit4] 2> 16767 T11 C7 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=25 status=0 QTime=0
[junit4] 2> ASYNC NEW_CORE C8 name=collection1 org.apache.solr.core.SolrCore@3899abfc
[junit4] 2> 17404 T11 C8 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[1234567890 (1463311076849352704)]} 0 2
[junit4] 2> 17406 T11 C8 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[2345678901 (1463311076852498432)]} 0 0
[junit4] 2> 17407 T11 C8 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 17464 T11 C8 oass.SolrIndexSearcher.<init> Opening Searcher@7106b5ae[collection1] main
[junit4] 2> 17465 T11 C8 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 17465 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@7106b5ae[collection1] main{StandardDirectoryReader(segments_1:29:nrt _a(5.0):C15 _b(5.0):C6 _c(5.0):C4 _d(5.0):C2)}
[junit4] 2> 17466 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 17466 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7106b5ae[collection1] main{StandardDirectoryReader(segments_1:29:nrt _a(5.0):C15 _b(5.0):C6 _c(5.0):C4 _d(5.0):C2)}
[junit4] 2> 17471 T11 C8 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 64
[junit4] 2> 17472 T11 C8 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=27 status=0 QTime=0
[junit4] 2> 17508 T11 C8 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[1234567891 (1463311076956307456)]} 0 4
[junit4] 2> 17513 T11 C8 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[2345678902 (1463311076962598912)]} 0 3
[junit4] 2> 17514 T11 C8 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 17574 T11 C8 oass.SolrIndexSearcher.<init> Opening Searcher@67c9166e[collection1] main
[junit4] 2> 17576 T11 C8 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 17576 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@67c9166e[collection1] main{StandardDirectoryReader(segments_1:31:nrt _a(5.0):C15 _b(5.0):C6 _c(5.0):C4 _d(5.0):C2 _e(5.0):C2)}
[junit4] 2> 17578 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 17578 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@67c9166e[collection1] main{StandardDirectoryReader(segments_1:31:nrt _a(5.0):C15 _b(5.0):C6 _c(5.0):C4 _d(5.0):C2 _e(5.0):C2)}
[junit4] 2> 17580 T11 C8 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 67
[junit4] 2> 17582 T11 C8 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=29 status=0 QTime=1
[junit4] 2> 17595 T11 C8 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[5234567890 (1463311077047533568)]} 0 3
[junit4] 2> 17599 T11 C8 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[6345678901 (1463311077052776448)]} 0 2
[junit4] 2> 17600 T11 C8 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 17662 T11 C8 oass.SolrIndexSearcher.<init> Opening Searcher@5f8a7192[collection1] main
[junit4] 2> 17664 T11 C8 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 17665 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@5f8a7192[collection1] main{StandardDirectoryReader(segments_1:33:nrt _a(5.0):C15 _b(5.0):C6 _c(5.0):C4 _d(5.0):C2 _e(5.0):C2 _f(5.0):C2)}
[junit4] 2> 17666 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 17666 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5f8a7192[collection1] main{StandardDirectoryReader(segments_1:33:nrt _a(5.0):C15 _b(5.0):C6 _c(5.0):C4 _d(5.0):C2 _e(5.0):C2 _f(5.0):C2)}
[junit4] 2> 17668 T11 C8 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 68
[junit4] 2> 17671 T11 C8 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=31 status=0 QTime=2
[junit4] 2> 17710 T11 C8 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[3234567890 (1463311077168119808)]} 0 3
[junit4] 2> 17715 T11 C8 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[4345678901 (1463311077174411264)]} 0 3
[junit4] 2> 17716 T11 C8 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 17724 T11 C8 oass.SolrIndexSearcher.<init> Opening Searcher@171ec62d[collection1] main
[junit4] 2> 17725 T11 C8 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 17725 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@171ec62d[collection1] main{StandardDirectoryReader(segments_1:35:nrt _a(5.0):C15 _b(5.0):C6 _c(5.0):C4 _d(5.0):C2 _e(5.0):C2 _f(5.0):C2 _g(5.0):C2)}
[junit4] 2> 17726 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 17726 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@171ec62d[collection1] main{StandardDirectoryReader(segments_1:35:nrt _a(5.0):C15 _b(5.0):C6 _c(5.0):C4 _d(5.0):C2 _e(5.0):C2 _f(5.0):C2 _g(5.0):C2)}
[junit4] 2> 17727 T11 C8 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 12
[junit4] 2> 17728 T11 C8 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=33 status=0 QTime=0
[junit4] 2> 17743 T11 C8 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[email.eml#0 (1463311077202722816)]} 0 4
[junit4] 2> 17744 T11 C8 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 17751 T11 C8 oass.SolrIndexSearcher.<init> Opening Searcher@4c0dc60d[collection1] main
[junit4] 2> 17752 T11 C8 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 17752 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@4c0dc60d[collection1] main{StandardDirectoryReader(segments_1:37:nrt _a(5.0):C15 _b(5.0):C6 _c(5.0):C4 _d(5.0):C2 _e(5.0):C2 _f(5.0):C2 _g(5.0):C2 _h(5.0):C1)}
[junit4] 2> 17753 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 17754 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4c0dc60d[collection1] main{StandardDirectoryReader(segments_1:37:nrt _a(5.0):C15 _b(5.0):C6 _c(5.0):C4 _d(5.0):C2 _e(5.0):C2 _f(5.0):C2 _g(5.0):C2 _h(5.0):C1)}
[junit4] 2> 17755 T11 C8 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 11
[junit4] 2> 17756 T11 C8 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=34 status=0 QTime=1
[junit4] 2> 17762 T11 oas.SolrTestCaseJ4.tearDown ###Ending testSolrCellDocumentTypes
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SolrCellMorphlineTest -Dtests.method=testSolrCellDocumentTypes -Dtests.seed=CE2FA82663A7CE5F -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=tr -Dtests.timezone=America/Recife -Dtests.file.encoding=UTF-8
[junit4] FAILURE 12.6s | SolrCellMorphlineTest.testSolrCellDocumentTypes <<<
[junit4] > Throwable #1: java.lang.AssertionError: key:ignored__attachment_mimetype expected:<[message/rfc822]> but was:<[text/plain]>
[junit4] > at __randomizedtesting.SeedInfo.seed([CE2FA82663A7CE5F:54EC0BB8067C908A]:0)
[junit4] > at org.apache.solr.morphlines.solr.AbstractSolrMorphlineTestBase.testDocumentTypesInternal(AbstractSolrMorphlineTestBase.java:171)
[junit4] > at org.apache.solr.morphlines.cell.SolrCellMorphlineTest.testSolrCellDocumentTypes(SolrCellMorphlineTest.java:193)
[junit4] > at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 17808 T11 oas.SolrTestCaseJ4.setUp ###Starting testSolrCellDocumentTypes2
[junit4] 2> 17836 T11 C8 oass.SolrIndexSearcher.<init> Opening Searcher@b584703[collection1] realtime
[junit4] 2> 17837 T11 C8 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {deleteByQuery=*:* (-1463311077275074560)} 0 29
[junit4] 2> 17837 T11 C8 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 17838 T11 C8 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@137a151c lockFactory=NativeFSLockFactory@/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-morphlines-cell/test/J0/./solrtest-SolrCellMorphlineTest-1395522174258/index),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@137a151c lockFactory=NativeFSLockFactory@/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-morphlines-cell/test/J0/./solrtest-SolrCellMorphlineTest-1395522174258/index),segFN=segments_2,generation=2}
[junit4] 2> 17839 T11 C8 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 17839 T11 C8 oass.SolrIndexSearcher.<init> Opening Searcher@4735824e[collection1] main
[junit4] 2> 17840 T11 C8 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 17840 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@4735824e[collection1] main{StandardDirectoryReader(segments_1:39:nrt)}
[junit4] 2> 17841 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 17841 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4735824e[collection1] main{StandardDirectoryReader(segments_1:39:nrt)}
[junit4] 2> 17845 T11 C8 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=false&waitSearcher=true} {commit=} 0 8
[junit4] 2> 17870 T11 okma.MorphlineContext.importCommandBuilders Importing commands
[junit4] 2> 18353 T11 okma.MorphlineContext.importCommandBuilders Done importing commands
[junit4] 2> 18816 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/'
[junit4] 2> 18859 T11 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 18860 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/extraction/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/extraction/lib).
[junit4] 2> 18861 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 18862 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/clustering/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/clustering/lib).
[junit4] 2> 18863 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 18863 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/langid/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/langid/lib).
[junit4] 2> 18864 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 18865 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/velocity/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/velocity/lib).
[junit4] 2> 18866 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 18866 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: /non/existent/dir/yields/warning (resolved as: /non/existent/dir/yields/warning).
[junit4] 2> 18916 T11 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4] 2> 18985 T11 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 18986 T11 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 19002 T11 oass.IndexSchema.readSchema [null] Schema name=example
[junit4] 2> 19431 T11 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 19452 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 19457 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 19489 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/'
[junit4] 2> 19525 T11 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 19526 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/extraction/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/extraction/lib).
[junit4] 2> 19527 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 19528 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/clustering/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/clustering/lib).
[junit4] 2> 19528 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 19529 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/langid/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/langid/lib).
[junit4] 2> 19530 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 19531 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/velocity/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/velocity/lib).
[junit4] 2> 19531 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 19532 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: /non/existent/dir/yields/warning (resolved as: /non/existent/dir/yields/warning).
[junit4] 2> 19571 T11 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4] 2> 19626 T11 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 19627 T11 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 19639 T11 oass.IndexSchema.readSchema [null] Schema name=example
[junit4] 2> 20011 T11 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 20034 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 20039 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 20070 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/'
[junit4] 2> 20101 T11 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 20102 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/extraction/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/extraction/lib).
[junit4] 2> 20102 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 20103 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/clustering/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/clustering/lib).
[junit4] 2> 20103 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 20104 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/langid/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/langid/lib).
[junit4] 2> 20104 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 20105 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/velocity/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/velocity/lib).
[junit4] 2> 20105 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 20106 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: /non/existent/dir/yields/warning (resolved as: /non/existent/dir/yields/warning).
[junit4] 2> 20144 T11 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4] 2> 20198 T11 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 20199 T11 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 20210 T11 oass.IndexSchema.readSchema [null] Schema name=example
[junit4] 2> 20651 T11 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 20674 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 20679 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 20701 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/'
[junit4] 2> 20729 T11 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 20730 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/extraction/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/extraction/lib).
[junit4] 2> 20730 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 20731 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/clustering/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/clustering/lib).
[junit4] 2> 20731 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 20732 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/langid/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/langid/lib).
[junit4] 2> 20732 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 20733 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../contrib/velocity/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../contrib/velocity/lib).
[junit4] 2> 20733 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/contrib/morphlines-core/src/test-files/solr/collection1/../../../dist).
[junit4] 2> 20734 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: /non/existent/dir/yields/warning (resolved as: /non/existent/dir/yields/warning).
[junit4] 2> 20778 T11 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4] 2> 20842 T11 oasc.SolrConfig.<init> Loaded SolrConfig: s
[...truncated too long message...]
optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 28988 T11 C16 oass.SolrIndexSearcher.<init> Opening Searcher@4686ee33[collection1] main
[junit4] 2> 28989 T11 C16 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 28989 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@4686ee33[collection1] main{StandardDirectoryReader(segments_4:97:nrt _18(5.0):C1)}
[junit4] 2> 28990 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 28990 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4686ee33[collection1] main{StandardDirectoryReader(segments_4:97:nrt _18(5.0):C1)}
[junit4] 2> 28991 T11 C16 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 7
[junit4] 2> 28992 T11 C16 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=1 status=0 QTime=0
[junit4] 2> 29008 T11 C16 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[testJPEG_EXIF.jpg.gz#0 (1463311089015980032)]} 0 4
[junit4] 2> 29009 T11 C16 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 29012 T11 C16 oass.SolrIndexSearcher.<init> Opening Searcher@78630ffa[collection1] main
[junit4] 2> 29012 T11 C16 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 29012 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@78630ffa[collection1] main{StandardDirectoryReader(segments_4:99:nrt _18(5.0):C1 _19(5.0):C1)}
[junit4] 2> 29013 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 29013 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@78630ffa[collection1] main{StandardDirectoryReader(segments_4:99:nrt _18(5.0):C1 _19(5.0):C1)}
[junit4] 2> 29014 T11 C16 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 5
[junit4] 2> 29014 T11 C16 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=2 status=0 QTime=0
[junit4] 2> 29031 T11 C16 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={} {add=[323b55ad-a438-4c9d-aeb9-43018ff894b6#0 (1463311089040097280)]} 0 4
[junit4] 2> 29032 T11 C16 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 29035 T11 C16 oass.SolrIndexSearcher.<init> Opening Searcher@27eb7071[collection1] main
[junit4] 2> 29036 T11 C16 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 29036 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@27eb7071[collection1] main{StandardDirectoryReader(segments_4:101:nrt _18(5.0):C1 _19(5.0):C1 _1a(5.0):C1)}
[junit4] 2> 29037 T13 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 29038 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@27eb7071[collection1] main{StandardDirectoryReader(segments_4:101:nrt _18(5.0):C1 _19(5.0):C1 _1a(5.0):C1)}
[junit4] 2> 29038 T11 C16 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 6
[junit4] 2> 29039 T11 C16 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=3 status=0 QTime=0
[junit4] 2> 29040 T11 C16 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 29041 T11 C16 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
[junit4] 2> 29041 T11 C16 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 29041 T11 C16 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=/update params={commit=true&softCommit=true&waitSearcher=true} {commit=} 0 1
[junit4] 2> 29042 T11 C16 oasc.SolrCore.execute [collection1] webapp=null path=/select params={q=*%3A*&rows=2147483647} hits=3 status=0 QTime=0
[junit4] 2> 29043 T11 oas.SolrTestCaseJ4.tearDown ###Ending testSolrCellJPGCompressed
[junit4] 2> 29045 T11 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 29046 T11 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1581263530
[junit4] 2> 29046 T11 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@3899abfc
[junit4] 2> 29048 T11 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=56,autocommit maxTime=60000ms,autocommits=0,soft autocommit maxTime=1000ms,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=3,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=61,cumulative_deletesById=0,cumulative_deletesByQuery=9,cumulative_errors=0,transaction_logs_total_size=118148,transaction_logs_total_number=9}
[junit4] 2> 29048 T11 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 29049 T11 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 29049 T11 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 29050 T11 C16 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@137a151c lockFactory=NativeFSLockFactory@/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-morphlines-cell/test/J0/./solrtest-SolrCellMorphlineTest-1395522174258/index),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@137a151c lockFactory=NativeFSLockFactory@/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-morphlines-cell/test/J0/./solrtest-SolrCellMorphlineTest-1395522174258/index),segFN=segments_5,generation=5}
[junit4] 2> 29050 T11 C16 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 29052 T11 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 29053 T11 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 29054 T11 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-morphlines-cell/test/J0/./solrtest-SolrCellMorphlineTest-1395522174258 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-morphlines-cell/test/J0/./solrtest-SolrCellMorphlineTest-1395522174258;done=false>>]
[junit4] 2> 29054 T11 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-morphlines-cell/test/J0/./solrtest-SolrCellMorphlineTest-1395522174258
[junit4] 2> 29055 T11 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-morphlines-cell/test/J0/./solrtest-SolrCellMorphlineTest-1395522174258/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-morphlines-cell/test/J0/./solrtest-SolrCellMorphlineTest-1395522174258/index;done=false>>]
[junit4] 2> 29055 T11 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/contrib/solr-morphlines-cell/test/J0/./solrtest-SolrCellMorphlineTest-1395522174258/index
[junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=DefaultSimilarity, locale=tr, timezone=America/Recife
[junit4] 2> NOTE: Linux 3.8.0-37-generic amd64/Oracle Corporation 1.7.0_60-ea (64-bit)/cpus=8,threads=1,free=64093888,total=190296064
[junit4] 2> NOTE: All tests run in this JVM: [SolrCellMorphlineTest]
[junit4] Completed in 29.22s, 5 tests, 1 failure <<< FAILURES!
[...truncated 9 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:209: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:440: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:490: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1275: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:907: There were test failures: 1 suite, 5 tests, 1 failure
Total time: 51 minutes 33 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_60-ea-b10 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_51) - Build #
9878 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9878/
Java: 32bit/jdk1.7.0_51 -client -XX:+UseG1GC
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([FB8F7F5387935FBC:FF87F0A09536B09D]: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:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1617)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at java.lang.Thread.run(Thread.java:744)
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:31)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
... 45 more
Build Log:
[...truncated 10509 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> 530497 T2445 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
[junit4] 2> 530498 T2445 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-OverseerTest-1395528106468
[junit4] 2> 530498 T2445 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 530501 T2445 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment
[junit4] 2> 530501 T2445 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 530502 T2446 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 530602 T2445 oasc.ZkTestServer.run start zk server on port:47494
[junit4] 2> 530603 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 530716 T2452 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d3b143 name:ZooKeeperConnection Watcher:127.0.0.1:47494 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 530717 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 530720 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 530720 T2454 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16f47c3 name:ZooKeeperConnection Watcher:127.0.0.1:47494 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 530721 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 530721 T2445 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 530724 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 530725 T2456 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14a4d3d name:ZooKeeperConnection Watcher:127.0.0.1:47494/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 530725 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 530725 T2445 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 530727 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 530728 T2458 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10ee421 name:ZooKeeperConnection Watcher:127.0.0.1:47494/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 530728 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 530729 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 530730 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 530733 T2445 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:47494_solr
[junit4] 2> 530733 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 530735 T2445 oasc.Overseer.start Overseer (id=91457329985814531-127.0.0.1:47494_solr-n_0000000000) starting
[junit4] 2> 530737 T2445 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 530739 T2445 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 530741 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 530743 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 530746 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 530749 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 530752 T2460 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 530753 T2445 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 530753 T2460 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 530753 T2459 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 530755 T2445 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 530756 T2445 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 530758 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 530759 T2462 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1aebb02 name:ZooKeeperConnection Watcher:127.0.0.1:47494/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 530759 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 530760 T2445 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 530762 T2445 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 530765 T2456 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 530765 T2462 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 530767 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 530769 T2459 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 530769 T2459 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> 530769 T2459 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 530769 T2459 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 530771 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 530772 T2462 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> 530772 T2456 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> 531267 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 531278 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 531282 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 531284 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 531284 T2459 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 531287 T2459 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> 531287 T2459 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 531287 T2459 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 531290 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 531394 T2462 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> 531394 T2456 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> 531784 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 531800 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 531803 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 531803 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 531803 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 531804 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 531804 T2459 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 531807 T2459 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> 531807 T2459 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 531807 T2459 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 531809 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 531913 T2462 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> 531913 T2456 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> 532304 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 532309 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 532312 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 532312 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 532313 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 532313 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 532313 T2459 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 532316 T2459 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node4",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 532316 T2459 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 532317 T2459 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 532318 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 532421 T2456 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> 532421 T2462 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> 532813 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 532821 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 532821 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 532821 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 532822 T2459 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 532822 T2459 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core5",
[junit4] 2> "core_node_name":"node5",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 532823 T2459 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 532823 T2459 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 532825 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 532936 T2462 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> 532936 T2456 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> 533321 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 533327 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 533327 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 533328 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 533329 T2459 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 533329 T2459 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core6",
[junit4] 2> "core_node_name":"node6",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 533330 T2459 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 533330 T2459 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 533331 T2458 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 533434 T2456 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> 533434 T2462 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> 533827 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 533833 T2462 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 533835 T2445 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:47494 47494
[junit4] 2> 534161 T2445 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 534166 T2445 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
[junit4] 2> 534166 T2445 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 534167 T2463 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 534267 T2445 oasc.ZkTestServer.run start zk server on port:45318
[junit4] 2> 534268 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 534289 T2469 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c25a81 name:ZooKeeperConnection Watcher:127.0.0.1:45318/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 534290 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 534291 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 534292 T2471 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@540ef5 name:ZooKeeperConnection Watcher:127.0.0.1:45318 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 534293 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 534309 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 534310 T2473 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@173c15c name:ZooKeeperConnection Watcher:127.0.0.1:45318 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 534310 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 534310 T2445 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 534312 T2445 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 534313 T2445 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 534315 T2445 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 534317 T2445 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 534319 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 534320 T2475 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15e78f6 name:ZooKeeperConnection Watcher:127.0.0.1:45318/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 534320 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 534320 T2445 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 534322 T2445 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 534324 T2475 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 534324 T2469 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 534324 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 534325 T2477 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@404f0c name:ZooKeeperConnection Watcher:127.0.0.1:45318/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 534325 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 534326 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 534327 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 534329 T2445 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:45318_solr
[junit4] 2> 534330 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 534331 T2445 oasc.Overseer.start Overseer (id=91457330226135044-127.0.0.1:45318_solr-n_0000000000) starting
[junit4] 2> 534332 T2445 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 534334 T2445 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 534336 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 534337 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 534339 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 534341 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 534344 T2479 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 534345 T2479 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 534345 T2478 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 534347 T2478 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 534347 T2478 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> 534348 T2478 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 534348 T2478 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 534351 T2477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 534351 T2469 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> 534352 T2475 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> 534846 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 534854 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 534859 T2477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 534859 T2445 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 534860 T2478 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 534861 T2469 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 534861 T2475 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 534862 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 534862 T2477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 534863 T2481 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5d626b name:ZooKeeperConnection Watcher:127.0.0.1:45318/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 534863 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 534864 T2445 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 534865 T2445 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 534867 T2469 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 534867 T2481 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 534869 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 534869 T2477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 534870 T2478 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> 534870 T2478 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 534872 T2477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 534872 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 534875 T2477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 534877 T2477 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 534980 T2469 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> 534980 T2481 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> 534981 T2445 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 534984 T2469 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 534984 T2481 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 534985 T2445 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:45318 45318
[junit4] 2> 535062 T2445 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 535067 T2445 oas.SolrTestCaseJ4.setUp ###Starting testPlaceholders
[junit4] 2> 535067 T2445 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 535067 T2482 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 535168 T2445 oasc.ZkTestServer.run start zk server on port:49522
[junit4] 2> 535169 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 535176 T2488 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@127446c name:ZooKeeperConnection Watcher:127.0.0.1:49522/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 535177 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 535177 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 535179 T2490 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@940140 name:ZooKeeperConnection Watcher:127.0.0.1:49522 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 535179 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 535195 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 535197 T2492 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13fff50 name:ZooKeeperConnection Watcher:127.0.0.1:49522 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 535197 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 535197 T2445 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 535200 T2445 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 535212 T2445 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 535216 T2445 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 535218 T2445 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 535222 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 535224 T2494 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c793a5 name:ZooKeeperConnection Watcher:127.0.0.1:49522/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 535225 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 535227 T2445 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 535230 T2445 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 535233 T2488 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 535233 T2494 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 535234 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 535235 T2496 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@69015b name:ZooKeeperConnection Watcher:127.0.0.1:49522/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 535235 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 535236 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 535238 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 535240 T2445 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:49522_solr
[junit4] 2> 535241 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 535242 T2445 oasc.Overseer.start Overseer (id=91457330285314052-127.0.0.1:49522_solr-n_0000000000) starting
[junit4] 2> 535243 T2445 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 535246 T2445 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 535250 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 535253 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 535259 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 535266 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 535275 T2498 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 535276 T2498 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 535276 T2497 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 535277 T2497 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 535278 T2497 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=12 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"12",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 535278 T2497 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
[junit4] 2> 535278 T2497 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard11
[junit4] 2> 535281 T2496 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 535281 T2488 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> 535281 T2494 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> 535333 T2462 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:1472)
[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:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 535334 T2462 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:1472)
[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:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 535335 T2462 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:1472)
[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:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 535777 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard11/election
[junit4] 2> 535785 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard11
[junit4] 2> 535790 T2496 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 535791 T2445 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 535791 T2497 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 535792 T2488 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 535793 T2494 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 535794 T2445 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49522 49522
[junit4] 2> 535918 T2445 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 535922 T2445 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 535923 T2445 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 535923 T2499 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 536023 T2445 oasc.ZkTestServer.run start zk server on port:53581
[junit4] 2> 536024 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 536027 T2505 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a70922 name:ZooKeeperConnection Watcher:127.0.0.1:53581/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 536027 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 536028 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 536029 T2507 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@341a1b name:ZooKeeperConnection Watcher:127.0.0.1:53581 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 536029 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 536041 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 536042 T2509 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@257a35 name:ZooKeeperConnection Watcher:127.0.0.1:53581 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 536042 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 536043 T2445 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 536044 T2445 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 536047 T2445 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 536049 T2445 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 536050 T2445 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 536052 T2445 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 536055 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 536056 T2511 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bea513 name:ZooKeeperConnection Watcher:127.0.0.1:53581/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 536056 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 536057 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 536058 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 536060 T2445 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53581_solr
[junit4] 2> 536060 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 536062 T2445 oasc.Overseer.start Overseer (id=91457330341543939-127.0.0.1:53581_solr-n_0000000000) starting
[junit4] 2> 536063 T2445 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 536065 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 536068 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 536069 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 536071 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 536074 T2513 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 536075 T2513 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 536076 T2512 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 536077 T2512 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 536078 T2512 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 536079 T2505 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 536082 T2512 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core2",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 536083 T2505 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 536084 T2512 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 536085 T2512 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 536085 T2512 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core3",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 536087 T2511 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 536088 T2505 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 536179 T2445 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53581 53581
[junit4] 2> 536250 T2445 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 536255 T2445 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
[junit4] 2> 536255 T2445 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 536256 T2514 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 536356 T2445 oasc.ZkTestServer.run start zk server on port:60603
[junit4] 2> 536357 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 536359 T2520 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@174eee3 name:ZooKeeperConnection Watcher:127.0.0.1:60603 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 536360 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 536379 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 536380 T2522 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1aec7c5 name:ZooKeeperConnection Watcher:127.0.0.1:60603 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 536380 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 536381 T2445 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 536384 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 536385 T2524 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a9f90 name:ZooKeeperConnection Watcher:127.0.0.1:60603/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 536386 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 536386 T2445 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 536389 T2445 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 536393 T2445 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 536395 T2445 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 536398 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 536400 T2526 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@125de6b name:ZooKeeperConnection Watcher:127.0.0.1:60603/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 536400 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 536402 T2445 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 536405 T2445 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 536408 T2526 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 536408 T2524 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 536409 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 536418 T2528 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b5af94 name:ZooKeeperConnection Watcher:127.0.0.1:60603/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 536419 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 536420 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 536423 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 536429 T2445 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60603_solr
[junit4] 2> 536430 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 536433 T2445 oasc.Overseer.start Overseer (id=91457330363301892-127.0.0.1:60603_solr-n_0000000000) starting
[junit4] 2> 536437 T2445 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 536441 T2445 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 536447 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 536453 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 536457 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 536459 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 536462 T2530 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 536462 T2530 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 536462 T2529 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 537465 T2528 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 537466 T2529 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 537467 T2529 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> 537467 T2529 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 537467 T2529 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 537478 T2528 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 537479 T2524 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> 537479 T2526 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> 537965 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 537978 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 537993 T2528 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 537993 T2445 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 537995 T2529 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 537998 T2528 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 537998 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 538000 T2529 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[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> 538000 T2529 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 538003 T2528 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 538176 T2524 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> 538176 T2526 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> 539232 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 539239 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 539240 T2532 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@163971f name:ZooKeeperConnection Watcher:127.0.0.1:60603/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 539240 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 539244 T2445 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60603_solr
[junit4] 2> 539245 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 539248 T2445 oasc.Overseer.start Overseer (id=91457330363301893-127.0.0.1:60603_solr-n_0000000001) starting
[junit4] 2> 539260 T2534 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 539261 T2533 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 539261 T2534 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 539263 T2533 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 539264 T2533 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> 539265 T2533 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 539268 T2532 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 539269 T2524 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> 539269 T2526 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> 539322 T2532 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 539322 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 539324 T2533 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 539326 T2526 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 539327 T2445 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91457330363301891-node1_core1-n_0000000002
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:276)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:273)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:273)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
[junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:666)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1617)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
[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:359)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
[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:359)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 539338 T2533 oasc.SolrException.log ERROR Problem cleaning up collection in zk:collection1:org.apache.zookeeper.KeeperException$NotEmptyException: KeeperErrorCode = Directory not empty for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:125)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:176)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:173)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:173)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:635)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:630)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:630)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:630)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:986)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:263)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:212)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 539338 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 539341 T2532 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 539341 T2533 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 539342 T2526 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 539343 T2532 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 539345 T2532 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 539346 T2533 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 539348 T2532 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 539450 T2524 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> 539450 T2526 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> 540342 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 541345 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 542348 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 543352 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 544355 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 545359 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 546362 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 547365 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 548369 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 549374 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 550377 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 551380 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 552383 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 553386 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 554408 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 554413 T2526 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 554413 T2524 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 554415 T2445 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:60603 60603
[junit4] 2> 554686 T2445 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=FB8F7F5387935FBC -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=zh -Dtests.timezone=Atlantic/Reykjavik -Dtests.file.encoding=US-ASCII
[junit4] ERROR 18.5s J0 | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
[junit4] > at __randomizedtesting.SeedInfo.seed([FB8F7F5387935FBC:FF87F0A09536B09D]:0)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
[junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
[junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:666)
[junit4] > at java.lang.Thread.run(Thread.java:744)
[junit4] > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:431)
[junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:428)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:385)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:372)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
[junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
[junit4] > ... 45 more
[junit4] 2> 554708 T2445 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
[junit4] 2> 554708 T2445 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 554708 T2535 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 554809 T2445 oasc.ZkTestServer.run start zk server on port:49144
[junit4] 2> 554810 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 554847 T2541 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19e8f53 name:ZooKeeperConnection Watcher:127.0.0.1:49144 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 554847 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 554863 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 554864 T2543 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1efab0f name:ZooKeeperConnection Watcher:127.0.0.1:49144 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 554864 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 554864 T2445 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 554869 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 554870 T2545 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6dad8d name:ZooKeeperConnection Watcher:127.0.0.1:49144/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 554870 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 554870 T2445 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 554872 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 554873 T2547 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13a8b90 name:ZooKeeperConnection Watcher:127.0.0.1:49144/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 554873 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 554874 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 554875 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 554878 T2445 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:49144_solr
[junit4] 2> 554878 T2445 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 554879 T2445 oasc.Overseer.start Overseer (id=91457331572703235-127.0.0.1:49144_solr-n_0000000000) starting
[junit4] 2> 554881 T2445 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 554882 T2445 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 554884 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 554885 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 554887 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 554889 T2445 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 554892 T2549 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 554892 T2445 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 554892 T2548 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 554892 T2549 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 554893 T2445 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 554894 T2445 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 554896 T2445 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 554897 T2551 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a58622 name:ZooKeeperConnection Watcher:127.0.0.1:49144/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 554898 T2445 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 554899 T2445 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 554901 T2445 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 554903 T2545 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 554903 T2551 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 554905 T2547 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 554906 T2548 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 554906 T2548 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> 554906 T2548 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 554907 T2548 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 554908 T2547 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 554909 T2545 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> 554909 T2551 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> 555405 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 555413 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 555418 T2547 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 555419 T2547 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 555419 T2548 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 555422 T2548 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> 555422 T2548 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 555423 T2548 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 555424 T2547 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 555527 T2551 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> 555527 T2545 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> 555919 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 555925 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 555928 T2547 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 555928 T2547 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 555929 T2547 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 555929 T2547 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 555929 T2548 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 555932 T2548 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> 555932 T2548 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 555933 T2548 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 555934 T2547 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 556052 T2545 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> 556052 T2551 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> 556430 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 556435 T2445 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 556438 T2547 oasc.DistributedQueue$La
[...truncated too long message...]
utor.ensureExists(ZkCmdExecutor.java:100)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.ensureExists(ZkCmdExecutor.java:94)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.<init>(DistributedQueue.java:61)
[junit4] 2> ... 8 more
[junit4] 2>
[junit4] 2> 570680 T2821 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 570681 T2823 oasc.Overseer.createOverseerNode ERROR Could not create Overseer node org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$9.execute(SolrZkClient.java:311)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$9.execute(SolrZkClient.java:308)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:308)
[junit4] 2> at org.apache.solr.cloud.Overseer.createOverseerNode(Overseer.java:1175)
[junit4] 2> at org.apache.solr.cloud.Overseer.getInQueue(Overseer.java:1139)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:146)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
[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:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 570681 T2823 oasc.LeaderElector$1.process WARN java.lang.RuntimeException: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer
[junit4] 2> at org.apache.solr.cloud.Overseer.createOverseerNode(Overseer.java:1184)
[junit4] 2> at org.apache.solr.cloud.Overseer.getInQueue(Overseer.java:1139)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:146)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
[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:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2> Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$9.execute(SolrZkClient.java:311)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$9.execute(SolrZkClient.java:308)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:308)
[junit4] 2> at org.apache.solr.cloud.Overseer.createOverseerNode(Overseer.java:1175)
[junit4] 2> ... 8 more
[junit4] 2>
[junit4] 2> 570682 T2823 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 570682 T2825 oasc.LeaderElector$1.process WARN org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
[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:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2> Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leaders/shard4
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:208)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:205)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:205)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:455)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:385)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:372)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
[junit4] 2> at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
[junit4] 2> ... 6 more
[junit4] 2>
[junit4] 2> 570682 T2825 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 572450 T2445 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene42, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=zh, timezone=Atlantic/Reykjavik
[junit4] 2> NOTE: Linux 3.8.0-37-generic i386/Oracle Corporation 1.7.0_51 (32-bit)/cpus=8,threads=1,free=149064840,total=510656512
[junit4] 2> NOTE: All tests run in this JVM: [RangeFacetTest, BlockCacheTest, BasicDistributedZkTest, TestPostingsSolrHighlighter, ClusterStateTest, DistributedTermsComponentTest, TestRemoteStreaming, TestRealTimeGet, TestManagedResourceStorage, CoreMergeIndexesAdminHandlerTest, TestSolrDeletionPolicy1, CoreAdminRequestStatusTest, TestAddFieldRealTimeGet, DistributedQueryComponentCustomSortTest, SolrInfoMBeanTest, TestClassNameShortening, LeaderElectionTest, ModifyConfFileTest, DistributedSpellCheckComponentTest, URLClassifyProcessorTest, ReturnFieldsTest, TestImplicitCoreProperties, SyncSliceTest, CachingDirectoryFactoryTest, AbstractAnalyticsStatsTest, ExternalFileFieldSortTest, TestCollapseQParserPlugin, TestSuggestSpellingConverter, DocValuesTest, DeleteShardTest, HdfsBasicDistributedZk2Test, TestSystemIdResolver, RegexBoostProcessorTest, TestGroupingSearch, TestPseudoReturnFields, TestLMDirichletSimilarityFactory, DistributedQueryElevationComponentTest, TestMiniSolrCloudCluster, MBeansHandlerTest, SampleTest, TestSearchPerf, TestSchemaSimilarityResource, ResourceLoaderTest, TestComplexPhraseQParserPlugin, TestFreeTextSuggestions, SynonymTokenizerTest, TestWriterPerf, BadComponentTest, OverseerRolesTest, SliceStateUpdateTest, TestManagedSchemaFieldResource, TestRandomDVFaceting, CoreAdminHandlerTest, AutoCommitTest, TestSolrQueryParser, TestDistributedMissingSort, CopyFieldTest, CursorMarkTest, UnloadDistributedZkTest, SuggesterFSTTest, OverseerTest]
[junit4] Completed on J0 in 41.98s, 9 tests, 1 error <<< FAILURES!
[...truncated 785 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:490: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1275: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:907: There were test failures: 391 suites, 1645 tests, 1 error, 49 ignored (28 assumptions)
Total time: 53 minutes 5 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_51 -client -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure