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/16 20:50:54 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.7.0_51) - Build # 9710
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9710/
Java: 32bit/jdk1.7.0_51 -client -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.TestDistributedGrouping.testDistribSearch
Error Message:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://[ff01::213]:33332/n_y/z, http://[ff01::114]:33332/n_y/z, http://127.0.0.1:55997/n_y/z]
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://[ff01::213]:33332/n_y/z, http://[ff01::114]:33332/n_y/z, http://127.0.0.1:55997/n_y/z]
at __randomizedtesting.SeedInfo.seed([1669EF57C26D8D4D:978F614FB532ED71]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:504)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:203)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91)
at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
at org.apache.solr.BaseDistributedSearchTestCase.queryServer(BaseDistributedSearchTestCase.java:515)
at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:563)
at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:545)
at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:524)
at org.apache.solr.TestDistributedGrouping.doTest(TestDistributedGrouping.java:62)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:876)
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 10749 lines...]
[junit4] Suite: org.apache.solr.TestDistributedGrouping
[junit4] 2> 927771 T3187 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
[junit4] 2> 927771 T3187 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /n_y/z
[junit4] 2> 927774 T3187 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 927775 T3187 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 927778 T3187 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:41181
[junit4] 2> 927779 T3187 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 927779 T3187 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 927779 T3187 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr
[junit4] 2> 927780 T3187 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/'
[junit4] 2> 927793 T3187 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/solr.xml
[junit4] 2> 927832 T3187 oasc.CoreContainer.<init> New CoreContainer 32421699
[junit4] 2> 927833 T3187 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/]
[junit4] 2> 927834 T3187 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 927834 T3187 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 927834 T3187 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 927835 T3187 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 927835 T3187 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 927835 T3187 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 927836 T3187 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 927836 T3187 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 927836 T3187 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 927837 T3187 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 927837 T3187 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 927837 T3187 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 927840 T3197 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1
[junit4] 2> 927841 T3197 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/'
[junit4] 2> 927842 T3197 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
[junit4] 2> 927843 T3197 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 927843 T3197 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 927907 T3197 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 927961 T3197 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 927961 T3197 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 927968 T3197 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 928357 T3197 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 928358 T3197 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 928358 T3197 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 928364 T3197 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 928367 T3197 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 928372 T3197 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 928375 T3197 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 928377 T3197 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 928378 T3197 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 928378 T3197 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 928378 T3197 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 928378 T3197 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 928379 T3197 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 928379 T3197 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 928379 T3197 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/, dataDir=./org.apache.solr.TestDistributedGrouping-1394998646214/control/data/
[junit4] 2> 928380 T3197 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ca7478
[junit4] 2> 928380 T3197 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.TestDistributedGrouping-1394998646214/control/data
[junit4] 2> 928380 T3197 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.TestDistributedGrouping-1394998646214/control/data/index/
[junit4] 2> 928381 T3197 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.TestDistributedGrouping-1394998646214/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 928381 T3197 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.TestDistributedGrouping-1394998646214/control/data/index
[junit4] 2> 928381 T3197 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1749865332, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 928382 T3197 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@162b3c6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12bdf0f)),segFN=segments_1,generation=1}
[junit4] 2> 928382 T3197 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 928383 T3197 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4] 2> 928385 T3197 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 928385 T3197 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 928386 T3197 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 928386 T3197 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 928386 T3197 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 928386 T3197 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 928387 T3197 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 928387 T3197 oasup.UniqFieldsUpdateProcessorFactory.init WARN Use of the 'fields' init param in UniqFieldsUpdateProcessorFactory is deprecated, please use 'fieldName' (or another FieldMutatingUpdateProcessorFactory selector option) instead
[junit4] 2> 928387 T3197 oasup.UniqFieldsUpdateProcessorFactory.init Replacing 'fields' init param with (individual) 'fieldName' params
[junit4] 2> 928387 T3197 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 928387 T3197 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 928388 T3197 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 928388 T3197 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 928388 T3197 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 928388 T3197 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 928389 T3197 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 928389 T3197 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 928390 T3197 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 928390 T3197 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4] 2> 928391 T3197 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4] 2> 928391 T3197 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 928391 T3197 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 928392 T3197 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 928392 T3197 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 928392 T3197 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 928393 T3197 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 928393 T3197 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 928393 T3197 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 928394 T3197 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 928394 T3197 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 928395 T3197 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 928395 T3197 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 928395 T3197 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 928396 T3197 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 928396 T3197 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4] 2> 928397 T3197 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 928399 T3197 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 928401 T3197 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 928403 T3197 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 928403 T3197 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 928404 T3197 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=41, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 928404 T3197 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@162b3c6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12bdf0f)),segFN=segments_1,generation=1}
[junit4] 2> 928404 T3197 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 928405 T3197 oass.SolrIndexSearcher.<init> Opening Searcher@1a535fa[collection1] main
[junit4] 2> 928405 T3197 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 928408 T3197 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 928425 T3198 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1a535fa[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 928430 T3197 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 928431 T3187 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 928431 T3187 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 928432 T3187 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 928434 T3187 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47194
[junit4] 2> 928436 T3187 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 928436 T3187 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 928437 T3187 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr
[junit4] 2> 928437 T3187 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/'
[junit4] 2> 928449 T3187 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/solr.xml
[junit4] 2> 928490 T3187 oasc.CoreContainer.<init> New CoreContainer 2084933
[junit4] 2> 928490 T3187 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/]
[junit4] 2> 928491 T3187 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 928492 T3187 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 928492 T3187 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 928492 T3187 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 928493 T3187 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 928493 T3187 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 928493 T3187 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 928493 T3187 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 928494 T3187 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 928494 T3187 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 928495 T3187 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 928495 T3187 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 928498 T3209 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1
[junit4] 2> 928499 T3209 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/'
[junit4] 2> 928499 T3209 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
[junit4] 2> 928500 T3209 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 928500 T3209 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 928550 T3209 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 928607 T3209 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 928607 T3209 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 928615 T3209 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 929013 T3209 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 929014 T3209 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 929015 T3209 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 929021 T3209 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 929023 T3209 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 929028 T3209 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 929030 T3209 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 929032 T3209 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 929033 T3209 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 929033 T3209 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 929033 T3209 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 929033 T3209 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 929034 T3209 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 929034 T3209 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 929034 T3209 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/, dataDir=./org.apache.solr.TestDistributedGrouping-1394998646214/shard0/data/
[junit4] 2> 929034 T3209 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ca7478
[junit4] 2> 929035 T3209 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.TestDistributedGrouping-1394998646214/shard0/data
[junit4] 2> 929035 T3209 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.TestDistributedGrouping-1394998646214/shard0/data/index/
[junit4] 2> 929035 T3209 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.TestDistributedGrouping-1394998646214/shard0/data/index' doesn't exist. Creating new index...
[junit4] 2> 929036 T3209 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.TestDistributedGrouping-1394998646214/shard0/data/index
[junit4] 2> 929036 T3209 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1749865332, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 929037 T3209 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@5b9b00 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@179565d)),segFN=segments_1,generation=1}
[junit4] 2> 929037 T3209 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 929037 T3209 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4] 2> 929040 T3209 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 929041 T3209 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 929041 T3209 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 929041 T3209 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 929041 T3209 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 929041 T3209 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 929042 T3209 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 929042 T3209 oasup.UniqFieldsUpdateProcessorFactory.init WARN Use of the 'fields' init param in UniqFieldsUpdateProcessorFactory is deprecated, please use 'fieldName' (or another FieldMutatingUpdateProcessorFactory selector option) instead
[junit4] 2> 929042 T3209 oasup.UniqFieldsUpdateProcessorFactory.init Replacing 'fields' init param with (individual) 'fieldName' params
[junit4] 2> 929042 T3209 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 929042 T3209 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 929043 T3209 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 929043 T3209 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 929043 T3209 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 929043 T3209 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 929044 T3209 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 929044 T3209 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 929045 T3209 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 929045 T3209 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4] 2> 929046 T3209 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4] 2> 929046 T3209 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 929047 T3209 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 929047 T3209 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 929047 T3209 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 929048 T3209 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 929048 T3209 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 929049 T3209 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 929049 T3209 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 929050 T3209 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 929050 T3209 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 929051 T3209 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 929052 T3209 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 929052 T3209 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 929053 T3209 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 929053 T3209 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4] 2> 929054 T3209 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 929056 T3209 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 929057 T3209 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 929059 T3209 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 929059 T3209 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 929061 T3209 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=41, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 929062 T3209 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@5b9b00 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@179565d)),segFN=segments_1,generation=1}
[junit4] 2> 929062 T3209 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 929063 T3209 oass.SolrIndexSearcher.<init> Opening Searcher@18ff1dd[collection1] main
[junit4] 2> 929063 T3209 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 929067 T3209 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 929101 T3210 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@18ff1dd[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 929118 T3209 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 929119 T3187 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 929120 T3187 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> ASYNC NEW_CORE C1906 name=collection1 org.apache.solr.core.SolrCore@111603a
[junit4] 2> 929124 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1462762101867020288)} 0 2
[junit4] 2> ASYNC NEW_CORE C1907 name=collection1 org.apache.solr.core.SolrCore@1146801
[junit4] 2> 929126 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1462762101869117440)} 0 1
[junit4] 2> 929128 T3194 C1906 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 929129 T3194 C1906 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 929130 T3194 C1906 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
[junit4] 2> 929130 T3194 C1906 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 929131 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={commit=true&wt=javabin&waitSearcher=true&softCommit=false&version=2} {commit=} 0 3
[junit4] 2> 929133 T3208 C1907 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 929134 T3208 C1907 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 929134 T3208 C1907 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
[junit4] 2> 929135 T3208 C1907 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 929136 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={commit=true&wt=javabin&waitSearcher=true&softCommit=false&version=2} {commit=} 0 3
[junit4] 2> 929140 T3195 C1906 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={q=*:*&wt=javabin&group=true&group.field=a_si&group.limit=10&version=2&sort=a_si+asc,+id+asc&distrib=false&fl=id,a_si&rows=100} hits=0 status=0 QTime=2
[junit4] 2> 929362 T3207 C1907 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={NOW=1394998647582&q=*:*&start=0&group=true&isShard=true&shard.url=[ff01::114]:33332/n_y/z|[ff01::083]:33332/n_y/z|http://127.0.0.1:47194/n_y/z|[ff01::213]:33332/n_y/z&group.limit=10&rows=100&distrib=false&group.distributed.first=true&wt=javabin&group.field=a_si&version=2&sort=a_si+asc,+id+asc&fl=id} status=0 QTime=9
[junit4] 2> 929372 T3205 C1907 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={q=*:*&shards=[ff01::114]:33332/n_y/z|[ff01::083]:33332/n_y/z|http://127.0.0.1:47194/n_y/z|[ff01::213]:33332/n_y/z&wt=javabin&group=true&group.field=a_si&group.limit=10&version=2&sort=a_si+asc,+id+asc&fl=id,a_si&rows=100} status=0 QTime=230
[junit4] 2> 929375 T3196 C1906 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={q=*:*&wt=javabin&group=true&group.field=a_si&hl=true&group.limit=10&version=2&hl.fl=a_t&sort=a_si+asc,+id+asc&distrib=false&fl=id,a_si&rows=100} hits=0 status=0 QTime=1
[junit4] 2> 929380 T3207 C1907 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={NOW=1394998647818&q=*:*&start=0&shard.url=[ff01::114]:33332/n_y/z|http://127.0.0.1:47194/n_y/z&isShard=true&group=true&group.limit=10&rows=100&distrib=false&group.distributed.first=true&wt=javabin&group.field=a_si&hl=false&version=2&hl.fl=a_t&sort=a_si+asc,+id+asc&fl=id} status=0 QTime=0
[junit4] 2> 929381 T3206 C1907 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={q=*:*&shards=[ff01::114]:33332/n_y/z|http://127.0.0.1:47194/n_y/z&wt=javabin&group=true&group.field=a_si&hl=true&group.limit=10&version=2&hl.fl=a_t&sort=a_si+asc,+id+asc&fl=id,a_si&rows=100} status=0 QTime=3
[junit4] 2> 929384 T3194 C1906 oasr.UnInvertedField.<init> UnInverted multi-valued field {field=a_t,memSize=4288,tindexSize=0,time=0,phase1=0,nTerms=0,bigTerms=0,termInstances=0,uses=0}
[junit4] 2> 929385 T3194 C1906 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={q=*:*&facet.field=a_t&wt=javabin&group=true&group.field=a_si&group.limit=10&version=2&sort=a_si+asc,+id+asc&facet=true&distrib=false&fl=id,a_si&rows=100} hits=0 status=0 QTime=1
[junit4] 2> 929390 T3208 C1907 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={NOW=1394998647827&q=*:*&facet.field=a_t&start=0&shard.url=http://127.0.0.1:47194/n_y/z|[ff01::213]:33332/n_y/z|[ff01::083]:33332/n_y/z&isShard=true&group=true&group.limit=10&rows=100&distrib=false&group.distributed.first=true&wt=javabin&group.field=a_si&version=2&sort=a_si+asc,+id+asc&facet=false&fl=id} status=0 QTime=1
[junit4] 2> 929395 T3207 C1907 oasr.UnInvertedField.<init> UnInverted multi-valued field {field=a_t,memSize=4288,tindexSize=0,time=0,phase1=0,nTerms=0,bigTerms=0,termInstances=0,uses=0}
[junit4] 2> 929396 T3207 C1907 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={NOW=1394998647827&q=*:*&facet.field=a_t&start=0&shard.url=http://127.0.0.1:47194/n_y/z|[ff01::213]:33332/n_y/z|[ff01::083]:33332/n_y/z&isShard=true&group=true&group.limit=10&distrib=false&rows=100&wt=javabin&group.distributed.second=true&f.a_t.facet.limit=160&group.field=a_si&version=2&sort=a_si+asc,+id+asc&facet=true&fl=id} status=0 QTime=4
[junit4] 2> 929399 T3205 C1907 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={q=*:*&facet.field=a_t&shards=http://127.0.0.1:47194/n_y/z|[ff01::213]:33332/n_y/z|[ff01::083]:33332/n_y/z&wt=javabin&group=true&group.field=a_si&group.limit=10&version=2&sort=a_si+asc,+id+asc&facet=true&fl=id,a_si&rows=100} status=0 QTime=12
[junit4] 2> 929402 T3195 C1906 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={q=*:*&stats=true&wt=javabin&group=true&group.field=a_si&group.limit=10&version=2&sort=a_si+asc,+id+asc&stats.field=a_si&distrib=false&fl=id,a_si&rows=100} hits=0 status=0 QTime=0
[junit4] 2> 929407 T3208 C1907 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={NOW=1394998647845&q=*:*&start=0&shard.url=[ff01::083]:33332/n_y/z|http://127.0.0.1:47194/n_y/z&isShard=true&group=true&group.limit=10&rows=100&distrib=false&group.distributed.first=true&stats=false&wt=javabin&group.field=a_si&version=2&sort=a_si+asc,+id+asc&stats.field=a_si&fl=id} status=0 QTime=0
[junit4] 2> 929410 T3207 C1907 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={NOW=1394998647845&q=*:*&start=0&shard.url=[ff01::083]:33332/n_y/z|http://127.0.0.1:47194/n_y/z&isShard=true&group=true&group.limit=10&rows=100&distrib=false&stats=true&wt=javabin&group.distributed.second=true&group.field=a_si&version=2&sort=a_si+asc,+id+asc&stats.field=a_si&fl=id} status=0 QTime=0
[junit4] 2> 929411 T3206 C1907 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={q=*:*&stats=true&shards=[ff01::083]:33332/n_y/z|http://127.0.0.1:47194/n_y/z&wt=javabin&group=true&group.field=a_si&group.limit=10&version=2&sort=a_si+asc,+id+asc&stats.field=a_si&fl=id,a_si&rows=100} status=0 QTime=6
[junit4] 2> 929428 T3196 C1906 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={spellcheck=true&q=kings&wt=javabin&group=true&spellcheck.build=true&group.field=a_si&qt=spellCheckCompRH&group.limit=10&version=2&sort=a_si+asc,+id+asc&distrib=false&fl=id,a_si&rows=100} hits=0 status=0 QTime=14
[junit4] 2> 929476 T3208 C1907 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={NOW=1394998647871&spellcheck=true&q=kings&start=0&spellcheck.count=5&shard.url=[ff01::114]:33332/n_y/z|http://127.0.0.1:47194/n_y/z|[ff01::213]:33332/n_y/z&isShard=true&group=true&group.limit=10&distrib=false&rows=100&group.distributed.first=true&spellcheck.onlyMorePopular=false&wt=javabin&spellcheck.build=true&group.field=a_si&spellcheck.extendedResults=false&version=2&sort=a_si+asc,+id+asc&fl=id} status=0 QTime=0
[junit4] 2> 929477 T3205 C1907 oashc.SpellCheckComponent.finishStage [ff01::114]:33332/n_y/z|http://127.0.0.1:47194/n_y/z|[ff01::213]:33332/n_y/z null
[junit4] 2> 929478 T3205 C1907 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={spellcheck=true&q=kings&shards=[ff01::114]:33332/n_y/z|http://127.0.0.1:47194/n_y/z|[ff01::213]:33332/n_y/z&wt=javabin&group=true&spellcheck.build=true&group.field=a_si&qt=spellCheckCompRH&group.limit=10&version=2&sort=a_si+asc,+id+asc&fl=id,a_si&rows=100} status=0 QTime=47
[junit4] 2> 929487 T3193 C1906 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={q=*:*&facet.field=a_t&fq=a_s:a&wt=javabin&group=true&group.field=a_si&group.limit=10&group.truncate=true&version=2&sort=a_si+asc,+id+asc&facet=true&distrib=false&fl=id,a_si&rows=100} hits=0 status=0 QTime=7
[junit4] 2> 929492 T3206 C1907 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={NOW=1394998647930&q=*:*&facet.field=a_t&fq=a_s:a&start=0&shard.url=http://127.0.0.1:47194/n_y/z|[ff01::114]:33332/n_y/z|[ff01::213]:33332/n_y/z|[ff01::083]:33332/n_y/z&isShard=true&group=true&group.limit=10&group.truncate=true&distrib=false&rows=100&group.distributed.first=true&wt=javabin&group.field=a_si&version=2&sort=a_si+asc,+id+asc&facet=false&fl=id} status=0 QTime=0
[junit4] 2> 929505 T3208 C1907 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={NOW=1394998647930&q=*:*&facet.field=a_t&fq=a_s:a&start=0&shard.url=http://127.0.0.1:47194/n_y/z|[ff01::114]:33332/n_y/z|[ff01::213]:33332/n_y/z|[ff01::083]:33332/n_y/z&isShard=true&group=true&group.limit=10&group.truncate=true&distrib=false&rows=100&wt=javabin&f.a_t.facet.limit=160&group.distributed.second=true&group.field=a_si&version=2&sort=a_si+asc,+id+asc&facet=true&fl=id} status=0 QTime=10
[junit4] 2> 929506 T3207 C1907 oasc.SolrCore.execute [collection1] webapp=/n_y/z path=/select params={q=*:*&facet.field=a_t&fq=a_s:a&shards=http://127.0.0.1:47194/n_y/z|[ff01::114]:33332/n_y/z|[ff01::213]:33332/n_y/z|[ff01::083]:33332/n_y/z&wt=javabin&group=true&group.field=a_si&group.limit=10&group.truncate=true&version=2&sort=a_si+asc,+id+asc&facet=true&fl=id,a_si&rows=100} status=0 QTime=16
[junit4] 2> 929512 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[1 (1462762102271770624)]} 0 3
[junit4] 2> 929516 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[1 (1462762102277013504)]} 0 2
[junit4] 2> 929520 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[2 (1462762102281207808)]} 0 2
[junit4] 2> 929525 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[2 (1462762102286450688)]} 0 2
[junit4] 2> 929528 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[3 (1462762102290644992)]} 0 1
[junit4] 2> 929532 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[3 (1462762102294839296)]} 0 2
[junit4] 2> 929537 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[4 (1462762102299033600)]} 0 2
[junit4] 2> 929541 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[4 (1462762102303227904)]} 0 2
[junit4] 2> 929545 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[5 (1462762102308470784)]} 0 1
[junit4] 2> 929549 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[5 (1462762102312665088)]} 0 1
[junit4] 2> 929554 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[6 (1462762102316859392)]} 0 2
[junit4] 2> 929558 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[6 (1462762102321053696)]} 0 2
[junit4] 2> 929562 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[7 (1462762102325248000)]} 0 2
[junit4] 2> 929566 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[7 (1462762102329442304)]} 0 2
[junit4] 2> 929570 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[8 (1462762102333636608)]} 0 2
[junit4] 2> 929574 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[8 (1462762102337830912)]} 0 2
[junit4] 2> 929578 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[9 (1462762102343073792)]} 0 2
[junit4] 2> 929582 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[9 (1462762102346219520)]} 0 2
[junit4] 2> 929586 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[10 (1462762102350413824)]} 0 2
[junit4] 2> 929590 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[10 (1462762102355656704)]} 0 2
[junit4] 2> 929594 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[11 (1462762102359851008)]} 0 2
[junit4] 2> 929598 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[11 (1462762102364045312)]} 0 1
[junit4] 2> 929602 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[12 (1462762102368239616)]} 0 1
[junit4] 2> 929606 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[12 (1462762102372433920)]} 0 1
[junit4] 2> 929611 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[14 (1462762102376628224)]} 0 2
[junit4] 2> 929615 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[14 (1462762102381871104)]} 0 1
[junit4] 2> 929619 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[15 (1462762102386065408)]} 0 1
[junit4] 2> 929623 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[15 (1462762102390259712)]} 0 1
[junit4] 2> 929627 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[16 (1462762102394454016)]} 0 1
[junit4] 2> 929631 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[16 (1462762102398648320)]} 0 1
[junit4] 2> 929640 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[17 (1462762102403891200)]} 0 6
[junit4] 2> 929649 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[17 (1462762102412279808)]} 0 6
[junit4] 2> 929653 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[18 (1462762102420668416)]} 0 2
[junit4] 2> 929657 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[18 (1462762102425911296)]} 0 2
[junit4] 2> 929661 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[19 (1462762102430105600)]} 0 1
[junit4] 2> 929665 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[19 (1462762102434299904)]} 0 1
[junit4] 2> 929669 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[20 (1462762102438494208)]} 0 1
[junit4] 2> 929673 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[20 (1462762102442688512)]} 0 1
[junit4] 2> 929677 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[21 (1462762102446882816)]} 0 1
[junit4] 2> 929682 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[21 (1462762102451077120)]} 0 2
[junit4] 2> 929686 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[22 (1462762102455271424)]} 0 2
[junit4] 2> 929690 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[22 (1462762102460514304)]} 0 2
[junit4] 2> 929694 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[23 (1462762102464708608)]} 0 1
[junit4] 2> 929698 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[23 (1462762102468902912)]} 0 1
[junit4] 2> 929702 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[100 (1462762102473097216)]} 0 1
[junit4] 2> 929706 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[100 (1462762102477291520)]} 0 1
[junit4] 2> 929710 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[101 (1462762102481485824)]} 0 1
[junit4] 2> 929714 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[101 (1462762102485680128)]} 0 1
[junit4] 2> 929718 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[102 (1462762102489874432)]} 0 1
[junit4] 2> 929722 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[102 (1462762102494068736)]} 0 1
[junit4] 2> 929726 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[103 (1462762102498263040)]} 0 1
[junit4] 2> 929730 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[103 (1462762102501408768)]} 0 2
[junit4] 2> 929734 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[104 (1462762102505603072)]} 0 2
[junit4] 2> 929737 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[104 (1462762102509797376)]} 0 1
[junit4] 2> 929741 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[105 (1462762102513991680)]} 0 1
[junit4] 2> 929745 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[105 (1462762102518185984)]} 0 1
[junit4] 2> 929749 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[106 (1462762102522380288)]} 0 1
[junit4] 2> 929753 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[106 (1462762102526574592)]} 0 1
[junit4] 2> 929757 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[107 (1462762102530768896)]} 0 1
[junit4] 2> 929761 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[107 (1462762102534963200)]} 0 2
[junit4] 2> 929765 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[108 (1462762102539157504)]} 0 2
[junit4] 2> 929769 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[108 (1462762102542303232)]} 0 2
[junit4] 2> 929773 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[109 (1462762102546497536)]} 0 2
[junit4] 2> 929777 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[109 (1462762102551740416)]} 0 2
[junit4] 2> 929781 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[110 (1462762102554886144)]} 0 2
[junit4] 2> 929785 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[110 (1462762102559080448)]} 0 2
[junit4] 2> 929789 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[111 (1462762102563274752)]} 0 2
[junit4] 2> 929792 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[111 (1462762102567469056)]} 0 1
[junit4] 2> 929796 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[112 (1462762102571663360)]} 0 1
[junit4] 2> 929800 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[112 (1462762102575857664)]} 0 1
[junit4] 2> 929804 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[113 (1462762102580051968)]} 0 1
[junit4] 2> 929808 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[113 (1462762102584246272)]} 0 1
[junit4] 2> 929812 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[114 (1462762102588440576)]} 0 1
[junit4] 2> 929816 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[114 (1462762102592634880)]} 0 1
[junit4] 2> 929820 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[115 (1462762102596829184)]} 0 1
[junit4] 2> 929824 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[115 (1462762102601023488)]} 0 1
[junit4] 2> 929828 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[116 (1462762102605217792)]} 0 1
[junit4] 2> 929832 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[116 (1462762102609412096)]} 0 1
[junit4] 2> 929836 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[117 (1462762102613606400)]} 0 1
[junit4] 2> 929840 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[117 (1462762102617800704)]} 0 1
[junit4] 2> 929844 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[118 (1462762102621995008)]} 0 1
[junit4] 2> 929848 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[118 (1462762102626189312)]} 0 1
[junit4] 2> 929852 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[119 (1462762102630383616)]} 0 1
[junit4] 2> 929856 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[119 (1462762102634577920)]} 0 1
[junit4] 2> 929860 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[120 (1462762102638772224)]} 0 1
[junit4] 2> 929864 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[120 (1462762102642966528)]} 0 1
[junit4] 2> 929868 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[121 (1462762102647160832)]} 0 1
[junit4] 2> 929872 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[121 (1462762102651355136)]} 0 1
[junit4] 2> 929876 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[122 (1462762102655549440)]} 0 2
[junit4] 2> 929880 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[122 (1462762102659743744)]} 0 2
[junit4] 2> 929884 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[123 (1462762102662889472)]} 0 2
[junit4] 2> 929888 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[123 (1462762102667083776)]} 0 2
[junit4] 2> 929891 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[124 (1462762102671278080)]} 0 1
[junit4] 2> 929895 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[124 (1462762102675472384)]} 0 1
[junit4] 2> 929899 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[125 (1462762102679666688)]} 0 1
[junit4] 2> 929903 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[125 (1462762102683860992)]} 0 1
[junit4] 2> 929906 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[126 (1462762102687006720)]} 0 1
[junit4] 2> 929908 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[126 (1462762102690152448)]} 0 0
[junit4] 2> 929911 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[127 (1462762102692249600)]} 0 1
[junit4] 2> 929913 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[127 (1462762102694346752)]} 0 1
[junit4] 2> 929916 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[128 (1462762102697492480)]} 0 1
[junit4] 2> 929918 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[128 (1462762102699589632)]} 0 1
[junit4] 2> 929920 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[129 (1462762102702735360)]} 0 0
[junit4] 2> 929923 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[129 (1462762102704832512)]} 0 1
[junit4] 2> 929925 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[130 (1462762102707978240)]} 0 0
[junit4] 2> 929928 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[130 (1462762102710075392)]} 0 1
[junit4] 2> 929930 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[131 (1462762102713221120)]} 0 0
[junit4] 2> 929933 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[131 (1462762102715318272)]} 0 1
[junit4] 2> 929935 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[132 (1462762102717415424)]} 0 1
[junit4] 2> 929937 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[132 (1462762102720561152)]} 0 0
[junit4] 2> 929940 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[133 (1462762102722658304)]} 0 1
[junit4] 2> 929942 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[133 (1462762102725804032)]} 0 0
[junit4] 2> 929945 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[134 (1462762102727901184)]} 0 1
[junit4] 2> 929947 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[134 (1462762102729998336)]} 0 1
[junit4] 2> 929949 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[135 (1462762102733144064)]} 0 0
[junit4] 2> 929952 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[135 (1462762102735241216)]} 0 1
[junit4] 2> 929954 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[136 (1462762102738386944)]} 0 0
[junit4] 2> 929957 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[136 (1462762102740484096)]} 0 1
[junit4] 2> 929959 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[137 (1462762102743629824)]} 0 0
[junit4] 2> 929962 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[137 (1462762102745726976)]} 0 1
[junit4] 2> 929964 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[138 (1462762102748872704)]} 0 0
[junit4] 2> 929967 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[138 (1462762102750969856)]} 0 1
[junit4] 2> 929969 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[139 (1462762102754115584)]} 0 1
[junit4] 2> 929972 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[139 (1462762102756212736)]} 0 1
[junit4] 2> 929974 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[140 (1462762102759358464)]} 0 1
[junit4] 2> 929977 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[140 (1462762102761455616)]} 0 1
[junit4] 2> 929980 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[141 (1462762102764601344)]} 0 1
[junit4] 2> 929982 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[141 (1462762102766698496)]} 0 1
[junit4] 2> 929984 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[142 (1462762102769844224)]} 0 0
[junit4] 2> 929987 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[142 (1462762102771941376)]} 0 1
[junit4] 2> 929989 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[143 (1462762102775087104)]} 0 0
[junit4] 2> 929992 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[143 (1462762102777184256)]} 0 1
[junit4] 2> 929994 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[144 (1462762102780329984)]} 0 0
[junit4] 2> 929997 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[144 (1462762102782427136)]} 0 1
[junit4] 2> 929999 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[145 (1462762102785572864)]} 0 0
[junit4] 2> 930002 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[145 (1462762102787670016)]} 0 1
[junit4] 2> 930004 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[146 (1462762102790815744)]} 0 0
[junit4] 2> 930007 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[146 (1462762102792912896)]} 0 1
[junit4] 2> 930009 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[147 (1462762102796058624)]} 0 0
[junit4] 2> 930012 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[147 (1462762102798155776)]} 0 1
[junit4] 2> 930014 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[148 (1462762102801301504)]} 0 0
[junit4] 2> 930017 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[148 (1462762102803398656)]} 0 1
[junit4] 2> 930019 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[149 (1462762102805495808)]} 0 1
[junit4] 2> 930021 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[149 (1462762102808641536)]} 0 0
[junit4] 2> 930024 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[500 (1462762102810738688)]} 0 1
[junit4] 2> 930027 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[500 (1462762102813884416)]} 0 1
[junit4] 2> 930029 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[501 (1462762102817030144)]} 0 0
[junit4] 2> 930031 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[501 (1462762102819127296)]} 0 0
[junit4] 2> 930033 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[502 (1462762102821224448)]} 0 0
[junit4] 2> 930036 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[502 (1462762102823321600)]} 0 1
[junit4] 2> 930038 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[503 (1462762102825418752)]} 0 1
[junit4] 2> 930040 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[503 (1462762102828564480)]} 0 0
[junit4] 2> 930042 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[504 (1462762102830661632)]} 0 0
[junit4] 2> 930045 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[504 (1462762102832758784)]} 0 1
[junit4] 2> 930047 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[505 (1462762102834855936)]} 0 1
[junit4] 2> 930049 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[505 (1462762102838001664)]} 0 0
[junit4] 2> 930051 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[506 (1462762102840098816)]} 0 0
[junit4] 2> 930053 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[506 (1462762102842195968)]} 0 0
[junit4] 2> 930056 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[507 (1462762102844293120)]} 0 1
[junit4] 2> 930058 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[507 (1462762102847438848)]} 0 1
[junit4] 2> 930060 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[508 (1462762102849536000)]} 0 0
[junit4] 2> 930062 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[508 (1462762102851633152)]} 0 0
[junit4] 2> 930064 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[509 (1462762102853730304)]} 0 0
[junit4] 2> 930067 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[509 (1462762102855827456)]} 0 1
[junit4] 2> 930069 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[510 (1462762102858973184)]} 0 1
[junit4] 2> 930071 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[510 (1462762102861070336)]} 0 0
[junit4] 2> 930073 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[511 (1462762102863167488)]} 0 0
[junit4] 2> 930075 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[511 (1462762102865264640)]} 0 0
[junit4] 2> 930078 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[512 (1462762102867361792)]} 0 1
[junit4] 2> 930080 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[512 (1462762102870507520)]} 0 0
[junit4] 2> 930082 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[513 (1462762102872604672)]} 0 0
[junit4] 2> 930085 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[513 (1462762102874701824)]} 0 1
[junit4] 2> 930087 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[514 (1462762102877847552)]} 0 0
[junit4] 2> 930090 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[514 (1462762102880993280)]} 0 0
[junit4] 2> 930093 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[515 (1462762102883090432)]} 0 1
[junit4] 2> 930095 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[515 (1462762102885187584)]} 0 1
[junit4] 2> 930097 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[516 (1462762102888333312)]} 0 0
[junit4] 2> 930099 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[516 (1462762102890430464)]} 0 0
[junit4] 2> 930101 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[517 (1462762102892527616)]} 0 0
[junit4] 2> 930104 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[517 (1462762102894624768)]} 0 1
[junit4] 2> 930106 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[518 (1462762102897770496)]} 0 1
[junit4] 2> 930108 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[518 (1462762102899867648)]} 0 0
[junit4] 2> 930110 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[519 (1462762102901964800)]} 0 0
[junit4] 2> 930112 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[519 (1462762102904061952)]} 0 0
[junit4] 2> 930115 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[520 (1462762102906159104)]} 0 1
[junit4] 2> 930117 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[520 (1462762102908256256)]} 0 1
[junit4] 2> 930119 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[521 (1462762102911401984)]} 0 0
[junit4] 2> 930121 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[521 (1462762102913499136)]} 0 0
[junit4] 2> 930124 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[522 (1462762102915596288)]} 0 1
[junit4] 2> 930126 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[522 (1462762102917693440)]} 0 1
[junit4] 2> 930128 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[523 (1462762102920839168)]} 0 0
[junit4] 2> 930130 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[523 (1462762102922936320)]} 0 0
[junit4] 2> 930132 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[524 (1462762102925033472)]} 0 0
[junit4] 2> 930135 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[524 (1462762102927130624)]} 0 1
[junit4] 2> 930137 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[525 (1462762102930276352)]} 0 1
[junit4] 2> 930139 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[525 (1462762102932373504)]} 0 0
[junit4] 2> 930141 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[526 (1462762102934470656)]} 0 0
[junit4] 2> 930144 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[526 (1462762102936567808)]} 0 1
[junit4] 2> 930146 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[527 (1462762102938664960)]} 0 1
[junit4] 2> 930148 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[527 (1462762102941810688)]} 0 0
[junit4] 2> 930150 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[528 (1462762102943907840)]} 0 0
[junit4] 2> 930152 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[528 (1462762102946004992)]} 0 0
[junit4] 2> 930155 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[529 (1462762102948102144)]} 0 1
[junit4] 2> 930157 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[529 (1462762102950199296)]} 0 1
[junit4] 2> 930159 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[530 (1462762102953345024)]} 0 0
[junit4] 2> 930161 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[530 (1462762102955442176)]} 0 0
[junit4] 2> 930163 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[531 (1462762102957539328)]} 0 0
[junit4] 2> 930166 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[531 (1462762102959636480)]} 0 1
[junit4] 2> 930168 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[532 (1462762102961733632)]} 0 1
[junit4] 2> 930170 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[532 (1462762102964879360)]} 0 0
[junit4] 2> 930172 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[533 (1462762102966976512)]} 0 0
[junit4] 2> 930174 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[533 (1462762102969073664)]} 0 0
[junit4] 2> 930177 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[534 (1462762102971170816)]} 0 1
[junit4] 2> 930179 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[534 (1462762102974316544)]} 0 1
[junit4] 2> 930181 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[535 (1462762102976413696)]} 0 0
[junit4] 2> 930183 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[535 (1462762102978510848)]} 0 0
[junit4] 2> 930185 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[536 (1462762102980608000)]} 0 0
[junit4] 2> 930188 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[536 (1462762102982705152)]} 0 1
[junit4] 2> 930190 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[537 (1462762102984802304)]} 0 1
[junit4] 2> 930192 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[537 (1462762102987948032)]} 0 0
[junit4] 2> 930194 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[538 (1462762102990045184)]} 0 0
[junit4] 2> 930196 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[538 (1462762102992142336)]} 0 0
[junit4] 2> 930199 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[539 (1462762102994239488)]} 0 1
[junit4] 2> 930201 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[539 (1462762102997385216)]} 0 1
[junit4] 2> 930203 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[540 (1462762102999482368)]} 0 0
[junit4] 2> 930205 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[540 (1462762103001579520)]} 0 0
[junit4] 2> 930208 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[541 (1462762103003676672)]} 0 1
[junit4] 2> 930210 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[541 (1462762103005773824)]} 0 1
[junit4] 2> 930213 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[542 (1462762103009968128)]} 0 0
[junit4] 2> 930216 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[542 (1462762103012065280)]} 0 1
[junit4] 2> 930218 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[543 (1462762103015211008)]} 0 0
[junit4] 2> 930220 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[543 (1462762103017308160)]} 0 0
[junit4] 2> 930223 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[544 (1462762103019405312)]} 0 1
[junit4] 2> 930225 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[544 (1462762103022551040)]} 0 1
[junit4] 2> 930227 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[545 (1462762103024648192)]} 0 0
[junit4] 2> 930229 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[545 (1462762103026745344)]} 0 0
[junit4] 2> 930232 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[546 (1462762103028842496)]} 0 1
[junit4] 2> 930234 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[546 (1462762103031988224)]} 0 1
[junit4] 2> 930236 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[547 (1462762103034085376)]} 0 0
[junit4] 2> 930238 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[547 (1462762103036182528)]} 0 0
[junit4] 2> 930241 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[548 (1462762103038279680)]} 0 1
[junit4] 2> 930243 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[548 (1462762103040376832)]} 0 1
[junit4] 2> 930245 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[549 (1462762103043522560)]} 0 0
[junit4] 2> 930247 T3206 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[549 (1462762103045619712)]} 0 0
[junit4] 2> 930249 T3195 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[550 (1462762103047716864)]} 0 0
[junit4] 2> 930252 T3207 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[550 (1462762103049814016)]} 0 1
[junit4] 2> 930254 T3196 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[551 (1462762103052959744)]} 0 0
[junit4] 2> 930256 T3208 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[551 (1462762103055056896)]} 0 0
[junit4] 2> 930258 T3193 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[552 (1462762103057154048)]} 0 0
[junit4] 2> 930261 T3205 C1907 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params={wt=javabin&version=2} {add=[552 (1462762103059251200)]} 0 1
[junit4] 2> 930263 T3194 C1906 oasup.LogUpdateProcessor.finish [collection1] webapp=/n_y/z path=/update params
[...truncated too long message...]
dex [CachedDir<<refCount=0;path=./org.apache.solr.TestDistributedGrouping-1394998646214/shard1/data/index;done=false>>]
[junit4] 2> 972368 T3187 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.TestDistributedGrouping-1394998646214/shard1/data/index
[junit4] 2> 972369 T3187 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/n_y/z,null}
[junit4] 2> 972441 T3187 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=26466859
[junit4] 2> 972442 T3187 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1db8d4d
[junit4] 2> 972469 T3187 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0,transaction_logs_total_size=67,transaction_logs_total_number=1}
[junit4] 2> 972469 T3187 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 972470 T3187 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 972470 T3187 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 972471 T3187 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 972471 T3187 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 972471 T3187 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.TestDistributedGrouping-1394998646214/shard2/data/index [CachedDir<<refCount=0;path=./org.apache.solr.TestDistributedGrouping-1394998646214/shard2/data/index;done=false>>]
[junit4] 2> 972472 T3187 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.TestDistributedGrouping-1394998646214/shard2/data/index
[junit4] 2> 972472 T3187 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.TestDistributedGrouping-1394998646214/shard2/data [CachedDir<<refCount=0;path=./org.apache.solr.TestDistributedGrouping-1394998646214/shard2/data;done=false>>]
[junit4] 2> 972472 T3187 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.TestDistributedGrouping-1394998646214/shard2/data
[junit4] 2> 972473 T3187 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/n_y/z,null}
[junit4] 2> 972534 T3187 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestDistributedGrouping -Dtests.method=testDistribSearch -Dtests.seed=1669EF57C26D8D4D -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=mt -Dtests.timezone=America/Belem -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 44.8s J1 | TestDistributedGrouping.testDistribSearch <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://[ff01::213]:33332/n_y/z, http://[ff01::114]:33332/n_y/z, http://127.0.0.1:55997/n_y/z]
[junit4] > at __randomizedtesting.SeedInfo.seed([1669EF57C26D8D4D:978F614FB532ED71]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:504)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:203)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
[junit4] > at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91)
[junit4] > at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.queryServer(BaseDistributedSearchTestCase.java:515)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:563)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:545)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:524)
[junit4] > at org.apache.solr.TestDistributedGrouping.doTest(TestDistributedGrouping.java:62)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:876)
[junit4] > at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 972541 T3187 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene46: {a_t=PostingsFormat(name=FSTOrdPulsing41), n_f1=MockVariableIntBlock(baseBlockSize=121), oddField_s=PostingsFormat(name=FSTPulsing41), other_tl1=MockVariableIntBlock(baseBlockSize=121), a_n_tdt=PostingsFormat(name=Memory doPackFST= true), n_dt1=MockVariableIntBlock(baseBlockSize=121), n_tdt1=MockVariableIntBlock(baseBlockSize=121), _version_=MockVariableIntBlock(baseBlockSize=121), n_l1=PostingsFormat(name=FSTOrdPulsing41), text=PostingsFormat(name=Memory doPackFST= true), a_s=PostingsFormat(name=Memory doPackFST= true), n_tl1=MockVariableIntBlock(baseBlockSize=121), range_facet_sl=PostingsFormat(name=FSTPulsing41), SubjectTerms_mfacet=MockVariableIntBlock(baseBlockSize=121), range_facet_si=PostingsFormat(name=FSTOrdPulsing41), foo_d=PostingsFormat(name=FSTPulsing41), foo_b=PostingsFormat(name=Memory doPackFST= true), intDefault=MockVariableIntBlock(baseBlockSize=121), b_n_tdt=MockVariableIntBlock(baseBlockSize=121), timestamp=PostingsFormat(name=FSTOrdPulsing41), n_tf1=PostingsFormat(name=FSTOrdPulsing41), rnd_b=PostingsFormat(name=FSTPulsing41), n_ti1=PostingsFormat(name=FSTPulsing41), range_facet_l=PostingsFormat(name=FSTOrdPulsing41), a_si=MockVariableIntBlock(baseBlockSize=121), id=PostingsFormat(name=FSTPulsing41), n_d1=PostingsFormat(name=FSTOrdPulsing41), n_td1=MockVariableIntBlock(baseBlockSize=121), foo_f=PostingsFormat(name=Memory doPackFST= true), multiDefault=PostingsFormat(name=FSTOrdPulsing41)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=mt, timezone=America/Belem
[junit4] 2> NOTE: Linux 3.8.0-36-generic i386/Oracle Corporation 1.7.0_51 (32-bit)/cpus=8,threads=1,free=218684640,total=396886016
[junit4] 2> NOTE: All tests run in this JVM: [TestAddFieldRealTimeGet, TestDistributedSearch, DateFieldTest, DocValuesMissingTest, SolrTestCaseJ4Test, DirectSolrConnectionTest, TestImplicitCoreProperties, TestRangeQuery, RequiredFieldsTest, OpenExchangeRatesOrgProviderTest, TestQuerySenderListener, MultiTermTest, TestDFRSimilarityFactory, DocValuesMultiTest, ShardRoutingCustomTest, TestExceedMaxTermLength, ChangedSchemaMergeTest, TestSweetSpotSimilarityFactory, TestPhraseSuggestions, DistribCursorPagingTest, TestSchemaNameResource, TermVectorComponentDistributedTest, TestMultiCoreConfBootstrap, BadIndexSchemaTest, XsltUpdateRequestHandlerTest, TestOmitPositions, SolrCmdDistributorTest, DistributedDebugComponentTest, TestLazyCores, TestSerializedLuceneMatchVersion, FullSolrCloudDistribCmdsTest, OpenCloseCoreStressTest, TestCollationFieldDocValues, SimplePostToolTest, ChaosMonkeyNothingIsSafeTest, TestCollationField, StressHdfsTest, SuggesterTSTTest, DistributedExpandComponentTest, HdfsCollectionsAPIDistributedZkTest, PreAnalyzedFieldTest, ZkSolrClientTest, TestFuzzyAnalyzedSuggestions, TestCodecSupport, SolrPluginUtilsTest, DisMaxRequestHandlerTest, TestSchemaResource, TestPartialUpdateDeduplication, TestSolrDeletionPolicy2, TimeZoneUtilsTest, HardAutoCommitTest, InfoHandlerTest, TestCloudManagedSchema, DistributedQueryComponentCustomSortTest, NumericFieldsTest, TestNumberUtils, TestFastWriter, UniqFieldsUpdateProcessorFactoryTest, TestFieldTypeCollectionResource, DebugComponentTest, TestSolrQueryParserDefaultOperatorResource, TestReloadAndDeleteDocs, DistanceFunctionTest, CachingDirectoryFactoryTest, IndexSchemaRuntimeFieldTest, TestSolr4Spatial, TestZkChroot, TestUpdate, TestFiltering, HdfsBasicDistributedZk2Test, SpellCheckComponentTest, TestRTGBase, BadCopyFieldTest, TestRecovery, TestStressRecovery, TestIBSimilarityFactory, XmlUpdateRequestHandlerTest, DocumentAnalysisRequestHandlerTest, StatsComponentTest, TestWordDelimiterFilterFactory, CollectionsAPIDistributedZkTest, TestIndexingPerformance, JSONWriterTest, AlternateDirectoryTest, RAMDirectoryFactoryTest, TestStressLucene, TestDistributedGrouping]
[junit4] Completed on J1 in 44.80s, 1 test, 1 error <<< FAILURES!
[...truncated 590 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:490: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1276: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:908: There were test failures: 370 suites, 1583 tests, 1 error, 38 ignored (17 assumptions)
Total time: 53 minutes 36 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_51 -client -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.8.0-fcs-b132) - Build #
9711 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9711/
Java: 32bit/jdk1.8.0-fcs-b132 -client -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.client.solrj.impl.CloudSolrServerTest.testShutdown
Error Message:
java.util.concurrent.TimeoutException: Could not connect to ZooKeeper 127.0.0.1:41060 within 45000 ms
Stack Trace:
org.apache.solr.common.SolrException: java.util.concurrent.TimeoutException: Could not connect to ZooKeeper 127.0.0.1:41060 within 45000 ms
at __randomizedtesting.SeedInfo.seed([30CDDAA28DB3A540:D3BBD3376AC93032]:0)
at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:150)
at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:101)
at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:91)
at org.apache.solr.cloud.AbstractZkTestCase.buildZooKeeper(AbstractZkTestCase.java:89)
at org.apache.solr.cloud.AbstractZkTestCase.buildZooKeeper(AbstractZkTestCase.java:83)
at org.apache.solr.cloud.AbstractDistribZkTestBase.setUp(AbstractDistribZkTestBase.java:70)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.setUp(AbstractFullDistribZkTestBase.java:201)
at org.apache.solr.client.solrj.impl.CloudSolrServerTest.setUp(CloudSolrServerTest.java:78)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1617)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:860)
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: java.util.concurrent.TimeoutException: Could not connect to ZooKeeper 127.0.0.1:41060 within 45000 ms
at org.apache.solr.common.cloud.ConnectionManager.waitForConnected(ConnectionManager.java:223)
at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:142)
... 45 more
Build Log:
[...truncated 11669 lines...]
[junit4] Suite: org.apache.solr.client.solrj.impl.CloudSolrServerTest
[junit4] 2> 706 T11 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 721 T11 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /n_af/d
[junit4] 2> 724 T11 oasc.AbstractZkTestCase.<clinit> WARN TEST_HOME() does not exist - solrj test?
[junit4] 2> 731 T11 oas.SolrTestCaseJ4.setUp ###Starting testShutdown
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./solrtest-CloudSolrServerTest-1395006029045
[junit4] 2> 735 T11 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 738 T12 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 837 T11 oasc.ZkTestServer.run start zk server on port:41060
[junit4] 2> 884 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 898 T13 oazs.NIOServerCnxn.doIO WARN Exception causing close of session 0x0 due to java.io.IOException: ZooKeeperServer not running
[junit4] 2> 55470 T15 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 52508ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
[junit4] 2> 55471 T11 oas.SolrTestCaseJ4.tearDown ###Ending testShutdown
[junit4] 2> 55484 T13 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144ccd6bd570000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 55486 T11 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:41060 41060
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CloudSolrServerTest -Dtests.method=testShutdown -Dtests.seed=30CDDAA28DB3A540 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=in -Dtests.timezone=Brazil/Acre -Dtests.file.encoding=UTF-8
[junit4] ERROR 54.9s J0 | CloudSolrServerTest.testShutdown <<<
[junit4] > Throwable #1: org.apache.solr.common.SolrException: java.util.concurrent.TimeoutException: Could not connect to ZooKeeper 127.0.0.1:41060 within 45000 ms
[junit4] > at __randomizedtesting.SeedInfo.seed([30CDDAA28DB3A540:D3BBD3376AC93032]:0)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:150)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:101)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:91)
[junit4] > at org.apache.solr.cloud.AbstractZkTestCase.buildZooKeeper(AbstractZkTestCase.java:89)
[junit4] > at org.apache.solr.cloud.AbstractZkTestCase.buildZooKeeper(AbstractZkTestCase.java:83)
[junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.setUp(AbstractDistribZkTestBase.java:70)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.setUp(AbstractFullDistribZkTestBase.java:201)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrServerTest.setUp(CloudSolrServerTest.java:78)
[junit4] > at java.lang.Thread.run(Thread.java:744)
[junit4] > Caused by: java.util.concurrent.TimeoutException: Could not connect to ZooKeeper 127.0.0.1:41060 within 45000 ms
[junit4] > at org.apache.solr.common.cloud.ConnectionManager.waitForConnected(ConnectionManager.java:223)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:142)
[junit4] > ... 45 more
[junit4] 2> 55649 T11 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./solrtest-CloudSolrServerTest-1395006083963
[junit4] 2> 55650 T11 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 55651 T19 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 55751 T11 oasc.ZkTestServer.run start zk server on port:53723
[junit4] 2> 55752 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 55763 T25 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e09e49 name:ZooKeeperConnection Watcher:127.0.0.1:53723 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 55763 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 55765 T11 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 55785 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 55789 T27 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c1c874 name:ZooKeeperConnection Watcher:127.0.0.1:53723/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 55789 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 55796 T11 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 55805 T11 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 55809 T11 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 55812 T11 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 55817 T11 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 55825 T11 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 55832 T11 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 55833 T11 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 55838 T11 oasc.AbstractZkTestCase.putConfig skipping /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml because it doesn't exist
[junit4] 2> 55839 T11 oasc.AbstractZkTestCase.putConfig skipping /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/stopwords.txt because it doesn't exist
[junit4] 2> 55839 T11 oasc.AbstractZkTestCase.putConfig skipping /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/protwords.txt because it doesn't exist
[junit4] 2> 55840 T11 oasc.AbstractZkTestCase.putConfig skipping /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/currency.xml because it doesn't exist
[junit4] 2> 55841 T11 oasc.AbstractZkTestCase.putConfig skipping /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/enumsConfig.xml because it doesn't exist
[junit4] 2> 55841 T11 oasc.AbstractZkTestCase.putConfig skipping /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/open-exchange-rates.json because it doesn't exist
[junit4] 2> 55842 T11 oasc.AbstractZkTestCase.putConfig skipping /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/mapping-ISOLatin1Accent.txt because it doesn't exist
[junit4] 2> 55843 T11 oasc.AbstractZkTestCase.putConfig skipping /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/old_synonyms.txt because it doesn't exist
[junit4] 2> 55843 T11 oasc.AbstractZkTestCase.putConfig skipping /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/solrj/src/test-files/solrj/solr/collection1/conf/synonyms.txt because it doesn't exist
[junit4] 2> 56069 T11 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 56160 T11 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50082
[junit4] 2> 56215 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 56216 T11 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 56216 T11 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-controljetty-1395006084158
[junit4] 2> 56216 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-controljetty-1395006084158/'
[junit4] 2> 56235 T11 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-controljetty-1395006084158/solr.xml
[junit4] 2> 56402 T11 oasc.CoreContainer.<init> New CoreContainer 7186327
[junit4] 2> 56403 T11 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-controljetty-1395006084158/]
[junit4] 2> 56423 T11 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 56424 T11 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
[junit4] 2> 56432 T11 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 56433 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 56433 T11 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 56434 T11 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 56435 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 56435 T11 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 56436 T11 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 56600 T11 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 56602 T11 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 56604 T11 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 56604 T11 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53723/solr
[junit4] 2> 56614 T11 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 56615 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 56620 T39 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@173baf0 name:ZooKeeperConnection Watcher:127.0.0.1:53723 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 56620 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 56626 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 56628 T41 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1026001 name:ZooKeeperConnection Watcher:127.0.0.1:53723/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 56628 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 56634 T11 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 56641 T11 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 56650 T11 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 56652 T11 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50082_n_af%2Fd
[junit4] 2> 56655 T11 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50082_n_af%2Fd
[junit4] 2> 56662 T11 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 56666 T11 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 56676 T11 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:50082_n_af%2Fd
[junit4] 2> 56677 T11 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 56680 T11 oasc.Overseer.start Overseer (id=91423118718795779-127.0.0.1:50082_n_af%2Fd-n_0000000000) starting
[junit4] 2> 56694 T11 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 56798 T43 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 56799 T11 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 56807 T11 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 56811 T11 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 56811 T43 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 56823 T42 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 56913 T44 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 56914 T44 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 56917 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 56917 T44 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 56921 T42 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 56922 T42 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:50082/n_af/d",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50082_n_af%2Fd",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 56923 T42 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 56933 T42 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 56938 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 56944 T41 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> 57918 T44 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 57919 T44 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-controljetty-1395006084158/collection1
[junit4] 2> 57920 T44 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 57920 T44 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 57921 T44 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 57922 T44 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 57923 T44 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-controljetty-1395006084158/collection1/'
[junit4] 2> 57990 T44 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 58033 T44 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 58042 T44 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 58100 T44 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 58157 T44 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [solr.SortableIntField]. Please consult documentation how to replace it accordingly.
[junit4] 2> 58162 T44 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [solr.SortableLongField]. Please consult documentation how to replace it accordingly.
[junit4] 2> 58167 T44 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [solr.SortableFloatField]. Please consult documentation how to replace it accordingly.
[junit4] 2> 58172 T44 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [solr.SortableDoubleField]. Please consult documentation how to replace it accordingly.
[junit4] 2> 58415 T44 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 58417 T44 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 58420 T44 oass.IndexSchema.readSchema WARN Field lowerfilt1and2 is not multivalued and destination for multiple copyFields (2)
[junit4] 2> 58420 T44 oass.IndexSchema.readSchema WARN Field text is not multivalued and destination for multiple copyFields (3)
[junit4] 2> 58464 T44 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 58474 T44 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-controljetty-1395006084158/collection1/, dataDir=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/control/data/
[junit4] 2> 58476 T44 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 58504 T44 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/control/data
[junit4] 2> 58505 T44 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/control/data/index/
[junit4] 2> 58505 T44 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 58518 T44 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/control/data/index
[junit4] 2> 58570 T44 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@15a77b1 lockFactory=NativeFSLockFactory@./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/control/data/index),segFN=segments_1,generation=1}
[junit4] 2> 58571 T44 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 58740 T44 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 58754 T44 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 58754 T44 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 58755 T44 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 58759 T44 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 58765 T44 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 58766 T44 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 58771 T44 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
[junit4] 2> 58798 T44 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 58827 T44 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 58827 T44 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 58829 T44 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@15a77b1 lockFactory=NativeFSLockFactory@./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/control/data/index),segFN=segments_1,generation=1}
[junit4] 2> 58830 T44 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 58843 T44 oass.SolrIndexSearcher.<init> Opening Searcher@6da5c0[collection1] main
[junit4] 2> 58878 T44 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 58878 T45 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6da5c0[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 58882 T11 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0
[junit4] 2> 58883 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 58882 T48 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50082/n_af/d collection:control_collection shard:shard1
[junit4] 2> 58893 T48 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 58904 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 58907 T50 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@979911 name:ZooKeeperConnection Watcher:127.0.0.1:53723/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 58908 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 58908 T48 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 58911 T11 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 58912 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 58913 T48 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 58913 T48 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 58914 T42 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 58917 T11 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> ASYNC NEW_CORE C0 name=collection1 org.apache.solr.core.SolrCore@1fdd9d8 url=http://127.0.0.1:50082/n_af/d/collection1 node=127.0.0.1:50082_n_af%2Fd C0_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:50082/n_af/d, core=collection1, node_name=127.0.0.1:50082_n_af%2Fd}
[junit4] 2> 58918 T48 C0 P50082 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50082/n_af/d/collection1/
[junit4] 2> 58920 T48 C0 P50082 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 58920 T48 C0 P50082 oasc.SyncStrategy.syncToMe http://127.0.0.1:50082/n_af/d/collection1/ has no replicas
[junit4] 2> 58921 T48 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50082/n_af/d/collection1/ shard1
[junit4] 2> 58924 T48 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 58924 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 58927 T50 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> 58927 T41 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> 58961 T11 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 58961 T11 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 58966 T11 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55444
[junit4] 2> 58967 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 58968 T11 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 58968 T11 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty1-1395006087231
[junit4] 2> 58969 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty1-1395006087231/'
[junit4] 2> 58994 T11 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty1-1395006087231/solr.xml
[junit4] 2> 59002 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 59005 T42 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 59009 T11 oasc.CoreContainer.<init> New CoreContainer 8648846
[junit4] 2> 59010 T11 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty1-1395006087231/]
[junit4] 2> 59010 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 59011 T11 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 59012 T11 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
[junit4] 2> 59013 T11 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 59013 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 59014 T11 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 59015 T11 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 59016 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 59016 T11 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 59017 T11 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 59018 T11 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 59019 T11 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 59019 T11 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 59020 T11 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53723/solr
[junit4] 2> 59020 T11 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 59021 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 59024 T61 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@54a454 name:ZooKeeperConnection Watcher:127.0.0.1:53723 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 59025 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 59028 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 59031 T63 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e40852 name:ZooKeeperConnection Watcher:127.0.0.1:53723/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 59032 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 59043 T11 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 59114 T50 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> 59115 T63 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> 59115 T41 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> 59154 T48 oasc.ZkController.register We are http://127.0.0.1:50082/n_af/d/collection1/ and leader is http://127.0.0.1:50082/n_af/d/collection1/
[junit4] 2> 59155 T48 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50082/n_af/d
[junit4] 2> 59155 T48 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 59155 T48 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 59155 T48 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 59157 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 59157 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 59157 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 59157 T48 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 59159 T42 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 59161 T42 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:50082/n_af/d",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50082_n_af%2Fd",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 59166 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 59270 T41 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> 59270 T63 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> 59270 T50 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> 60051 T11 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55444_n_af%2Fd
[junit4] 2> 60054 T11 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55444_n_af%2Fd
[junit4] 2> 60060 T41 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 60060 T63 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 60060 T50 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 60076 T64 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 60077 T64 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 60079 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 60079 T64 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 60079 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 60080 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 60084 T42 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 60085 T42 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:55444/n_af/d",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55444_n_af%2Fd",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 60086 T42 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 60087 T42 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 60094 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 60200 T50 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 60201 T63 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 60201 T41 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 61080 T64 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 61080 T64 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty1-1395006087231/collection1
[junit4] 2> 61081 T64 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 61082 T64 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 61082 T64 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 61083 T64 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 61084 T64 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty1-1395006087231/collection1/'
[junit4] 2> 61117 T64 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 61133 T64 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 61135 T64 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 61168 T64 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 61339 T64 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 61340 T64 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 61342 T64 oass.IndexSchema.readSchema WARN Field lowerfilt1and2 is not multivalued and destination for multiple copyFields (2)
[junit4] 2> 61343 T64 oass.IndexSchema.readSchema WARN Field text is not multivalued and destination for multiple copyFields (3)
[junit4] 2> 61344 T64 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 61345 T64 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty1-1395006087231/collection1/, dataDir=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty1/
[junit4] 2> 61346 T64 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 61347 T64 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty1
[junit4] 2> 61347 T64 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty1/index/
[junit4] 2> 61348 T64 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 61348 T64 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty1/index
[junit4] 2> 61350 T64 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@e757b7 lockFactory=NativeFSLockFactory@./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty1/index),segFN=segments_1,generation=1}
[junit4] 2> 61350 T64 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 61351 T64 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 61352 T64 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 61352 T64 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 61352 T64 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 61353 T64 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 61353 T64 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 61353 T64 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 61353 T64 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
[junit4] 2> 61356 T64 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 61357 T64 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 61358 T64 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 61358 T64 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@e757b7 lockFactory=NativeFSLockFactory@./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty1/index),segFN=segments_1,generation=1}
[junit4] 2> 61359 T64 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 61359 T64 oass.SolrIndexSearcher.<init> Opening Searcher@11f646d[collection1] main
[junit4] 2> 61360 T65 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@11f646d[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 61360 T64 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 61361 T11 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0
[junit4] 2> 61361 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 61361 T68 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55444/n_af/d collection:collection1 shard:shard2
[junit4] 2> 61363 T68 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 61374 T68 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 61376 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 61377 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 61377 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 61378 T68 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 61378 T68 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1 name=collection1 org.apache.solr.core.SolrCore@83ac50 url=http://127.0.0.1:55444/n_af/d/collection1 node=127.0.0.1:55444_n_af%2Fd C1_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:55444/n_af/d, core=collection1, node_name=127.0.0.1:55444_n_af%2Fd}
[junit4] 2> 61378 T68 C1 P55444 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55444/n_af/d/collection1/
[junit4] 2> 61378 T42 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 61379 T68 C1 P55444 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 61379 T68 C1 P55444 oasc.SyncStrategy.syncToMe http://127.0.0.1:55444/n_af/d/collection1/ has no replicas
[junit4] 2> 61380 T68 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55444/n_af/d/collection1/ shard2
[junit4] 2> 61380 T68 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 61384 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 61388 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 61393 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 61398 T11 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 61399 T11 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 61401 T11 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50282
[junit4] 2> 61402 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 61403 T11 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 61403 T11 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty2-1395006089675
[junit4] 2> 61404 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty2-1395006089675/'
[junit4] 2> 61423 T11 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty2-1395006089675/solr.xml
[junit4] 2> 61460 T11 oasc.CoreContainer.<init> New CoreContainer 22103547
[junit4] 2> 61460 T11 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty2-1395006089675/]
[junit4] 2> 61461 T11 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 61462 T11 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
[junit4] 2> 61462 T11 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 61463 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 61463 T11 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 61463 T11 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 61464 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 61464 T11 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 61465 T11 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 61465 T11 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 61466 T11 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 61466 T11 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 61467 T11 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53723/solr
[junit4] 2> 61467 T11 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 61468 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 61470 T79 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11d42aa name:ZooKeeperConnection Watcher:127.0.0.1:53723 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 61470 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 61473 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 61474 T81 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a43980 name:ZooKeeperConnection Watcher:127.0.0.1:53723/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 61474 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 61479 T11 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 61498 T41 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 61498 T81 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 61498 T63 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 61498 T50 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 61506 T68 oasc.ZkController.register We are http://127.0.0.1:55444/n_af/d/collection1/ and leader is http://127.0.0.1:55444/n_af/d/collection1/
[junit4] 2> 61507 T68 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55444/n_af/d
[junit4] 2> 61507 T68 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 61507 T68 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 61507 T68 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 61509 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 61509 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 61509 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 61510 T68 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 61511 T42 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 61512 T42 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:55444/n_af/d",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55444_n_af%2Fd",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 61515 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 61618 T41 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 61618 T63 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 61618 T81 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 61618 T50 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 62482 T11 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50282_n_af%2Fd
[junit4] 2> 62484 T11 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50282_n_af%2Fd
[junit4] 2> 62487 T41 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 62487 T50 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 62487 T81 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 62487 T63 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 62493 T82 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 62494 T82 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 62495 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 62495 T82 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 62495 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 62495 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 62497 T42 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 62498 T42 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:50282/n_af/d",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50282_n_af%2Fd",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 62498 T42 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 62498 T42 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 62502 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 62604 T50 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 62605 T63 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 62604 T81 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 62604 T41 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 63495 T82 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 63496 T82 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty2-1395006089675/collection1
[junit4] 2> 63496 T82 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 63497 T82 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 63497 T82 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 63498 T82 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 63498 T82 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty2-1395006089675/collection1/'
[junit4] 2> 63523 T82 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 63533 T82 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 63535 T82 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 63549 T82 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 63675 T82 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 63677 T82 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 63678 T82 oass.IndexSchema.readSchema WARN Field lowerfilt1and2 is not multivalued and destination for multiple copyFields (2)
[junit4] 2> 63679 T82 oass.IndexSchema.readSchema WARN Field text is not multivalued and destination for multiple copyFields (3)
[junit4] 2> 63680 T82 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 63680 T82 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty2-1395006089675/collection1/, dataDir=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty2/
[junit4] 2> 63680 T82 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 63681 T82 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty2
[junit4] 2> 63681 T82 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty2/index/
[junit4] 2> 63682 T82 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 63682 T82 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty2/index
[junit4] 2> 63683 T82 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@135b12e lockFactory=NativeFSLockFactory@./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty2/index),segFN=segments_1,generation=1}
[junit4] 2> 63684 T82 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 63685 T82 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 63685 T82 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 63685 T82 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 63685 T82 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 63686 T82 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 63686 T82 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 63686 T82 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 63687 T82 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
[junit4] 2> 63689 T82 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 63691 T82 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 63691 T82 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 63692 T82 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@135b12e lockFactory=NativeFSLockFactory@./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty2/index),segFN=segments_1,generation=1}
[junit4] 2> 63692 T82 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 63693 T82 oass.SolrIndexSearcher.<init> Opening Searcher@bcf60f[collection1] main
[junit4] 2> 63694 T83 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@bcf60f[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 63694 T82 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 63695 T11 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0
[junit4] 2> 63695 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 63695 T86 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50282/n_af/d collection:collection1 shard:shard1
[junit4] 2> 63697 T86 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 63705 T86 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 63708 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 63709 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 63709 T86 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 63709 T86 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 63709 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> ASYNC NEW_CORE C2 name=collection1 org.apache.solr.core.SolrCore@1e558f5 url=http://127.0.0.1:50282/n_af/d/collection1 node=127.0.0.1:50282_n_af%2Fd C2_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:50282/n_af/d, core=collection1, node_name=127.0.0.1:50282_n_af%2Fd}
[junit4] 2> 63710 T86 C2 P50282 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50282/n_af/d/collection1/
[junit4] 2> 63711 T42 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 63711 T86 C2 P50282 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 63712 T86 C2 P50282 oasc.SyncStrategy.syncToMe http://127.0.0.1:50282/n_af/d/collection1/ has no replicas
[junit4] 2> 63712 T86 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50282/n_af/d/collection1/ shard1
[junit4] 2> 63712 T86 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 63716 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 63721 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 63725 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 63732 T11 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 63732 T11 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 63734 T11 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52567
[junit4] 2> 63735 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 63735 T11 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 63737 T11 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty3-1395006092008
[junit4] 2> 63737 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty3-1395006092008/'
[junit4] 2> 63757 T11 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty3-1395006092008/solr.xml
[junit4] 2> 63778 T11 oasc.CoreContainer.<init> New CoreContainer 30283463
[junit4] 2> 63779 T11 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty3-1395006092008/]
[junit4] 2> 63780 T11 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 63780 T11 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
[junit4] 2> 63781 T11 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 63781 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 63782 T11 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 63782 T11 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 63783 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 63783 T11 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 63784 T11 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 63785 T11 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 63785 T11 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 63786 T11 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 63787 T11 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53723/solr
[junit4] 2> 63787 T11 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 63788 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 63791 T97 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a123f2 name:ZooKeeperConnection Watcher:127.0.0.1:53723 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 63792 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 63795 T11 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 63797 T99 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e1b37 name:ZooKeeperConnection Watcher:127.0.0.1:53723/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 63797 T11 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 63802 T11 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 63830 T50 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 63831 T99 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 63830 T41 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 63830 T81 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 63830 T63 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 63873 T86 oasc.ZkController.register We are http://127.0.0.1:50282/n_af/d/collection1/ and leader is http://127.0.0.1:50282/n_af/d/collection1/
[junit4] 2> 63873 T86 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50282/n_af/d
[junit4] 2> 63873 T86 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 63874 T86 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 63874 T86 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 63875 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 63876 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 63876 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 63876 T86 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 63877 T42 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 63878 T42 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:50282/n_af/d",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50282_n_af%2Fd",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 63881 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 63984 T41 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 63984 T99 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 63984 T63 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 63984 T50 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 63984 T81 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 64806 T11 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52567_n_af%2Fd
[junit4] 2> 64807 T11 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52567_n_af%2Fd
[junit4] 2> 64810 T81 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 64810 T99 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 64810 T63 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 64810 T50 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 64810 T41 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 64820 T100 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 64820 T100 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 64841 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 64841 T100 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 64841 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 64842 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 64843 T42 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 64844 T42 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:52567/n_af/d",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52567_n_af%2Fd",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 64844 T42 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 64845 T42 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 64848 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 64951 T50 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 64951 T41 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 64951 T63 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 64951 T99 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 64951 T81 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 65842 T100 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 65842 T100 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty3-1395006092008/collection1
[junit4] 2> 65842 T100 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 65843 T100 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 65844 T100 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 65845 T100 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 65845 T100 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty3-1395006092008/collection1/'
[junit4] 2> 65865 T100 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 65872 T100 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 65874 T100 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 65885 T100 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 66002 T100 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 66004 T100 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 66005 T100 oass.IndexSchema.readSchema WARN Field lowerfilt1and2 is not multivalued and destination for multiple copyFields (2)
[junit4] 2> 66006 T100 oass.IndexSchema.readSchema WARN Field text is not multivalued and destination for multiple copyFields (3)
[junit4] 2> 66006 T100 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 66007 T100 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./org.apache.solr.client.solrj.impl.CloudSolrServerTest-jetty3-1395006092008/collection1/, dataDir=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty3/
[junit4] 2> 66007 T100 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 66008 T100 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty3
[junit4] 2> 66008 T100 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty3/index/
[junit4] 2> 66008 T100 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 66009 T100 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty3/index
[junit4] 2> 66011 T100 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@b33d7a lockFactory=NativeFSLockFactory@./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty3/index),segFN=segments_1,generation=1}
[junit4] 2> 66011 T100 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 66013 T100 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 66013 T100 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 66013 T100 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 66014 T100 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 66014 T100 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 66014 T100 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 66015 T100 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 66015 T100 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
[junit4] 2> 66016 T100 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 66017 T100 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 66018 T100 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 66019 T100 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@b33d7a lockFactory=NativeFSLockFactory@./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty3/index),segFN=segments_1,generation=1}
[junit4] 2> 66019 T100 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 66019 T100 oass.SolrIndexSearcher.<init> Opening Searcher@616229[collection1] main
[junit4] 2> 66020 T100 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 66020 T101 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@616229[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 66021 T11 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0
[junit4] 2> 66021 T11 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 66021 T104 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52567/n_af/d collection:collection1 shard:shard2
[junit4] 2> 66026 T104 oasc.ZkController.register We are http://127.0.0.1:52567/n_af/d/collection1/ and leader is http://127.0.0.1:55444/n_af/d/collection1/
[junit4] 2> 66026 T104 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52567/n_af/d
[junit4] 2> 66026 T104 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 66026 T104 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C3 name=collection1 org.apache.solr.core.SolrCore@19f3730 url=http://127.0.0.1:52567/n_af/d/collection1 node=127.0.0.1:52567_n_af%2Fd C3_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:52567/n_af/d, core=collection1, node_name=127.0.0.1:52567_n_af%2Fd}
[junit4] 2> 66031 T105 C3 P52567 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 66033 T104 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 66034 T105 C3 P52567 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 66035 T105 C3 P52567 oasc.ZkController.publish publishing core=collection1 state=recovering collection=collection1
[junit4] 2> 66036 T105 C3 P52567 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 66037 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 66038 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 66038 T41 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 66043 T42 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[...truncated too long message...]
mShards not found on descriptor - reading it from system property
[junit4] 2> 75588 T50 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 75610 T11 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/n_af/d,null}
[junit4] 2> 75663 T11 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 50082
[junit4] 2> 75668 T11 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 75670 T11 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53723 53723
[junit4] 2> 77851 T99 C10 P52567 oasc.SyncStrategy.sync WARN Closed, skipping sync up.
[junit4] 2> 77937 T118 C11 P55442 oasc.SyncStrategy.sync WARN Closed, skipping sync up.
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 85763 T11 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 85764 T118 oasc.ShardLeaderElectionContext.rejoinLeaderElection Not rejoining election because CoreContainer is shutdown
[junit4] 2> 85764 T118 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@194cd59
[junit4] 2> 85765 T118 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=6,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=2,cumulative_deletesById=1,cumulative_deletesByQuery=2,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=5}
[junit4] 2> 85765 T118 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 85766 T99 oasc.ShardLeaderElectionContext.rejoinLeaderElection Not rejoining election because CoreContainer is shutdown
[junit4] 2> 85766 T118 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 85766 T118 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 85766 T99 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@19f3730
[junit4] 2> 85768 T99 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=6,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=2,cumulative_deletesById=1,cumulative_deletesByQuery=2,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=5}
[junit4] 2> 85769 T118 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 85769 T99 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 85769 T118 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 85769 T99 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 85769 T118 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty4/index;done=false>>]
[junit4] 2> 85770 T99 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 85770 T118 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty4/index
[junit4] 2> 85770 T118 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty4 [CachedDir<<refCount=0;path=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty4;done=false>>]
[junit4] 2> 85771 T118 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty4
[junit4] 2> 85771 T118 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 85771 T99 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 85771 T118 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 85772 T99 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 85773 T99 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty3 [CachedDir<<refCount=0;path=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty3;done=false>>]
[junit4] 2> 85773 T99 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty3
[junit4] 2> 85773 T99 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty3/index [CachedDir<<refCount=0;path=./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty3/index;done=false>>]
[junit4] 2> 85773 T99 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.client.solrj.impl.CloudSolrServerTest-1395006083963/jetty3/index
[junit4] 2> 85774 T99 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 85774 T99 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 85774 T99 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 85775 T99 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> NOTE: test params are: codec=Lucene3x, sim=DefaultSimilarity, locale=in, timezone=Brazil/Acre
[junit4] 2> NOTE: Linux 3.8.0-36-generic i386/Oracle Corporation 1.8.0 (32-bit)/cpus=8,threads=1,free=119646064,total=197656576
[junit4] 2> NOTE: All tests run in this JVM: [ContentStreamTest, CloudSolrServerTest]
[junit4] Completed on J0 in 86.32s, 2 tests, 1 error <<< FAILURES!
[...truncated 115 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:202: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:490: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1276: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:908: There were test failures: 49 suites, 283 tests, 1 error
Total time: 51 minutes 17 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0-fcs-b132 -client -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure