You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/08/09 13:59:25 UTC
[JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 345 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/345/
4 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.RecoveryZkTest
Error Message:
Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=1091, name=coreLoadExecutor-690-thread-1, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
Stack Trace:
com.carrotsearch.randomizedtesting.ResourceDisposalError: Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=1091, name=coreLoadExecutor-690-thread-1, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
at __randomizedtesting.SeedInfo.seed([F95BA0F3810C538F]:0)
at java.lang.Thread.getStackTrace(Thread.java:1568)
at com.carrotsearch.randomizedtesting.RandomizedContext.closeAtEnd(RandomizedContext.java:150)
at org.apache.lucene.util.LuceneTestCase.closeAfterSuite(LuceneTestCase.java:545)
at org.apache.lucene.util.LuceneTestCase.wrapDirectory(LuceneTestCase.java:1035)
at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:927)
at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:919)
at org.apache.solr.core.MockDirectoryFactory.create(MockDirectoryFactory.java:37)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:350)
at org.apache.solr.core.SolrCore.getNewIndexDir(SolrCore.java:250)
at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:464)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:754)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:624)
at org.apache.solr.core.ZkContainer.createFromZk(ZkContainer.java:235)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:551)
at org.apache.solr.core.CoreContainer$1.call(CoreContainer.java:245)
at org.apache.solr.core.CoreContainer$1.call(CoreContainer.java:237)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:724)
Caused by: java.lang.AssertionError: Directory not closed: MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@448ef279 lockFactory=org.apache.lucene.store.NativeFSLockFactory@10616b5f))
at org.junit.Assert.fail(Assert.java:93)
at org.apache.lucene.util.CloseableDirectory.close(CloseableDirectory.java:47)
at com.carrotsearch.randomizedtesting.RandomizedRunner$2$1.apply(RandomizedRunner.java:602)
at com.carrotsearch.randomizedtesting.RandomizedRunner$2$1.apply(RandomizedRunner.java:599)
at com.carrotsearch.randomizedtesting.RandomizedContext.closeResources(RandomizedContext.java:167)
at com.carrotsearch.randomizedtesting.RandomizedRunner$2.afterAlways(RandomizedRunner.java:615)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:43)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
... 1 more
REGRESSION: org.apache.solr.handler.admin.ShowFileRequestHandlerTest.test404ViaHttp
Error Message:
expected:<404> but was:<500>
Stack Trace:
java.lang.AssertionError: expected:<404> but was:<500>
at __randomizedtesting.SeedInfo.seed([F95BA0F3810C538F:25F816EEAF204753]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.handler.admin.ShowFileRequestHandlerTest.test404ViaHttp(ShowFileRequestHandlerTest.java:58)
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:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
REGRESSION: org.apache.solr.handler.admin.ShowFileRequestHandlerTest.testGetRawFile
Error Message:
Server at https://127.0.0.1:57819/solr/collection1 returned non ok status:500, message:{msg=SolrCore 'collection1' is not available due to init failure: Error loading class 'solr.clustering.ClusteringComponent',trace=org.apache.solr.common.SolrException: SolrCore 'collection1' is not available due to init failure: Error loading class 'solr.clustering.ClusteringComponent' at org.apache.solr.core.CoreContainer.getCore(CoreContainer.java:779) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:250) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:158) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419) at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:136) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:455) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229) at org.eclipse.jetty.server.handler.Scope
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at https://127.0.0.1:57819/solr/collection1 returned non ok status:500, message:{msg=SolrCore 'collection1' is not available due to init failure: Error loading class 'solr.clustering.ClusteringComponent',trace=org.apache.solr.common.SolrException: SolrCore 'collection1' is not available due to init failure: Error loading class 'solr.clustering.ClusteringComponent' at org.apache.solr.core.CoreContainer.getCore(CoreContainer.java:779) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:250) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:158) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419) at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:136) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:455) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229) at org.eclipse.jetty.server.handler.Scope
at __randomizedtesting.SeedInfo.seed([F95BA0F3810C538F:275608194BD137B6]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.handler.admin.ShowFileRequestHandlerTest.testGetRawFile(ShowFileRequestHandlerTest.java:123)
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:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
REGRESSION: org.apache.solr.handler.admin.ShowFileRequestHandlerTest.testDirList
Error Message:
Server at https://127.0.0.1:57819/solr/collection1 returned non ok status:500, message:{msg=SolrCore 'collection1' is not available due to init failure: Error loading class 'solr.clustering.ClusteringComponent',trace=org.apache.solr.common.SolrException: SolrCore 'collection1' is not available due to init failure: Error loading class 'solr.clustering.ClusteringComponent' at org.apache.solr.core.CoreContainer.getCore(CoreContainer.java:779) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:250) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:158) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419) at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:136) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:455) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229) at org.eclipse.jetty.server.handler.Scope
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at https://127.0.0.1:57819/solr/collection1 returned non ok status:500, message:{msg=SolrCore 'collection1' is not available due to init failure: Error loading class 'solr.clustering.ClusteringComponent',trace=org.apache.solr.common.SolrException: SolrCore 'collection1' is not available due to init failure: Error loading class 'solr.clustering.ClusteringComponent' at org.apache.solr.core.CoreContainer.getCore(CoreContainer.java:779) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:250) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:158) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419) at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:136) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:455) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229) at org.eclipse.jetty.server.handler.Scope
at __randomizedtesting.SeedInfo.seed([F95BA0F3810C538F:1063B1014952C9B5]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:90)
at org.apache.solr.handler.admin.ShowFileRequestHandlerTest.testDirList(ShowFileRequestHandlerTest.java:89)
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:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 9728 lines...]
[junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
[junit4] 2> 319973 T949 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 319977 T949 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./solrtest-RecoveryZkTest-1376046931371
[junit4] 2> 319978 T949 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 319979 T950 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 320080 T949 oasc.ZkTestServer.run start zk server on port:17150
[junit4] 2> 320081 T949 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 320084 T956 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8d0f23a name:ZooKeeperConnection Watcher:127.0.0.1:17150 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 320085 T949 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 320085 T949 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 320103 T949 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 320105 T958 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@db1fd67 name:ZooKeeperConnection Watcher:127.0.0.1:17150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 320105 T949 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 320106 T949 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 320116 T949 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 320119 T949 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 320121 T949 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 320130 T949 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 320131 T949 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 320136 T949 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 320137 T949 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 320244 T949 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 320245 T949 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 320248 T949 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 320248 T949 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 320260 T949 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 320260 T949 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 320263 T949 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 320264 T949 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 320294 T949 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 320295 T949 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 320298 T949 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 320299 T949 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 320308 T949 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 320308 T949 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 320311 T949 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 320312 T949 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 320509 T949 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 320514 T949 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:17153
[junit4] 2> 320514 T949 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 320515 T949 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 320515 T949 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1376046931715
[junit4] 2> 320515 T949 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1376046931715/'
[junit4] 2> 320542 T949 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1376046931715/solr.xml
[junit4] 2> 320625 T949 oasc.CoreContainer.<init> New CoreContainer 383068401
[junit4] 2> 320626 T949 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1376046931715/]
[junit4] 2> 320628 T949 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 320628 T949 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 320629 T949 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 320629 T949 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 320629 T949 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 320630 T949 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 320630 T949 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 320630 T949 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 320631 T949 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 320631 T949 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 320648 T949 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:17150/solr
[junit4] 2> 320648 T949 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 320649 T949 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 320656 T969 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@47b94293 name:ZooKeeperConnection Watcher:127.0.0.1:17150 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 320657 T949 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 320669 T949 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 320680 T949 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 320682 T971 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@35f975e2 name:ZooKeeperConnection Watcher:127.0.0.1:17150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 320682 T949 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 320689 T949 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 320694 T949 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 320703 T949 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 320706 T949 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:17153_
[junit4] 2> 320713 T949 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:17153_
[junit4] 2> 320716 T949 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 320730 T949 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 320738 T949 oasc.Overseer.start Overseer (id=90180611694657539-127.0.0.1:17153_-n_0000000000) starting
[junit4] 2> 320748 T949 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 320759 T973 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 320760 T949 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 320763 T949 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 320765 T949 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 320768 T972 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 320774 T974 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 320774 T974 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 320775 T974 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 322272 T972 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 322273 T972 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":null,
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:17153_",
[junit4] 2> "base_url":"http://127.0.0.1:17153"}
[junit4] 2> 322273 T972 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 322273 T972 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 322290 T971 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> 322777 T974 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 322777 T974 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1376046931715/collection1
[junit4] 2> 322777 T974 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 322778 T974 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 322778 T974 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 322779 T974 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1376046931715/collection1/'
[junit4] 2> 322781 T974 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1376046931715/collection1/lib/README' to classloader
[junit4] 2> 322782 T974 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1376046931715/collection1/lib/classes/' to classloader
[junit4] 2> 322838 T974 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 322899 T974 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 323000 T974 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 323010 T974 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 323562 T974 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 323571 T974 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 323581 T974 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 323594 T974 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 323598 T974 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 323601 T974 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 323602 T974 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 323603 T974 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 323603 T974 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 323604 T974 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 323604 T974 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 323604 T974 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 323604 T974 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1376046931715/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1376046931370/control/data/
[junit4] 2> 323604 T974 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@32b029b6
[junit4] 2> 323605 T974 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1376046931370/control/data
[junit4] 2> 323605 T974 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1376046931370/control/data/index/
[junit4] 2> 323605 T974 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1376046931370/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 323606 T974 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1376046931370/control/data/index
[junit4] 2> 323609 T974 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@1613a15f lockFactory=org.apache.lucene.store.NativeFSLockFactory@6944dc22; maxCacheMB=0.76171875 maxMergeSizeMB=0.10546875)),segFN=segments_1,generation=1}
[junit4] 2> 323609 T974 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 323613 T974 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 323613 T974 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 323613 T974 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 323614 T974 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 323614 T974 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 323614 T974 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 323614 T974 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 323615 T974 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 323615 T974 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 323627 T974 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 323632 T974 oass.SolrIndexSearcher.<init> Opening Searcher@4cf6582d main
[junit4] 2> 323633 T974 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 323633 T974 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 323636 T975 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4cf6582d main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 323637 T974 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 323637 T974 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:17153 collection:control_collection shard:shard1
[junit4] 2> 323637 T974 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 323649 T974 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 323668 T974 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 323678 T974 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 323678 T974 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 323678 T974 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:17153/collection1/
[junit4] 2> 323678 T974 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 323678 T974 oasc.SyncStrategy.syncToMe http://127.0.0.1:17153/collection1/ has no replicas
[junit4] 2> 323678 T974 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:17153/collection1/ shard1
[junit4] 2> 323679 T974 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 323794 T972 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 323810 T971 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> 323837 T974 oasc.ZkController.register We are http://127.0.0.1:17153/collection1/ and leader is http://127.0.0.1:17153/collection1/
[junit4] 2> 323837 T974 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:17153
[junit4] 2> 323837 T974 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 323837 T974 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 323837 T974 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 323839 T974 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 323840 T949 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0
[junit4] 2> 323841 T949 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 323841 T949 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 323848 T949 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 323849 T949 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 323851 T978 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@712d3d44 name:ZooKeeperConnection Watcher:127.0.0.1:17150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 323851 T949 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 323852 T949 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 323854 T949 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 324159 T949 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 324163 T949 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:17157
[junit4] 2> 324163 T949 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 324164 T949 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 324164 T949 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1376046935248
[junit4] 2> 324165 T949 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1376046935248/'
[junit4] 2> 324204 T949 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1376046935248/solr.xml
[junit4] 2> 324293 T949 oasc.CoreContainer.<init> New CoreContainer 623050796
[junit4] 2> 324294 T949 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1376046935248/]
[junit4] 2> 324295 T949 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 324296 T949 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 324296 T949 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 324296 T949 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 324297 T949 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 324297 T949 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 324297 T949 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 324298 T949 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 324298 T949 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 324299 T949 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 324314 T949 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:17150/solr
[junit4] 2> 324315 T949 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 324316 T949 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 324319 T989 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a4c3f9d name:ZooKeeperConnection Watcher:127.0.0.1:17150 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 324319 T949 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 324339 T949 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 324349 T949 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 324351 T991 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2bff2d04 name:ZooKeeperConnection Watcher:127.0.0.1:17150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 324351 T949 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 324360 T949 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 325325 T972 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 325326 T972 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "roles":null,
[junit4] 2> "state":"active",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:17153_",
[junit4] 2> "base_url":"http://127.0.0.1:17153"}
[junit4] 2> 325343 T971 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> 325343 T991 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> 325343 T978 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> 325364 T949 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:17157_
[junit4] 2> 325366 T949 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:17157_
[junit4] 2> 325368 T991 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 325369 T971 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 325369 T978 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 325369 T971 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 325369 T978 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 325370 T991 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 325384 T992 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 325384 T992 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 325385 T992 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 326850 T972 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 326851 T972 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":null,
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:17157_",
[junit4] 2> "base_url":"http://127.0.0.1:17157"}
[junit4] 2> 326851 T972 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 326852 T972 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 326864 T971 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> 326864 T991 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> 326864 T978 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> 327388 T992 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 327388 T992 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1376046935248/collection1
[junit4] 2> 327388 T992 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 327389 T992 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 327389 T992 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 327390 T992 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1376046935248/collection1/'
[junit4] 2> 327392 T992 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1376046935248/collection1/lib/README' to classloader
[junit4] 2> 327393 T992 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1376046935248/collection1/lib/classes/' to classloader
[junit4] 2> 327455 T992 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 327520 T992 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 327622 T992 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 327633 T992 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 328279 T992 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 328295 T992 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 328299 T992 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 328315 T992 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 328320 T992 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 328325 T992 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 328326 T992 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 328326 T992 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 328327 T992 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 328328 T992 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 328328 T992 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 328328 T992 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 328329 T992 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1376046935248/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1376046931370/jetty1/
[junit4] 2> 328329 T992 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@32b029b6
[junit4] 2> 328330 T992 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1376046931370/jetty1
[junit4] 2> 328330 T992 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1376046931370/jetty1/index/
[junit4] 2> 328330 T992 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1376046931370/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 328331 T992 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1376046931370/jetty1/index
[junit4] 2> 328335 T992 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@35817d7b lockFactory=org.apache.lucene.store.NativeFSLockFactory@9813867; maxCacheMB=0.76171875 maxMergeSizeMB=0.10546875)),segFN=segments_1,generation=1}
[junit4] 2> 328335 T992 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 328341 T992 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 328341 T992 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 328342 T992 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 328343 T992 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 328343 T992 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 328344 T992 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 328351 T992 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 328352 T992 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 328353 T992 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 328371 T992 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 328378 T992 oass.SolrIndexSearcher.<init> Opening Searcher@ca5fc00 main
[junit4] 2> 328380 T992 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 328380 T992 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 328386 T993 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ca5fc00 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 328388 T992 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 328389 T992 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:17157 collection:collection1 shard:shard1
[junit4] 2> 328389 T992 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 328407 T992 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 328437 T992 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 328448 T992 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 328449 T992 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 328449 T992 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:17157/collection1/
[junit4] 2> 328449 T992 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 328449 T992 oasc.SyncStrategy.syncToMe http://127.0.0.1:17157/collection1/ has no replicas
[junit4] 2> 328449 T992 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:17157/collection1/ shard1
[junit4] 2> 328450 T992 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 329870 T972 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 329943 T978 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> 329943 T991 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> 329943 T971 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> 329993 T992 oasc.ZkController.register We are http://127.0.0.1:17157/collection1/ and leader is http://127.0.0.1:17157/collection1/
[junit4] 2> 329993 T992 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:17157
[junit4] 2> 329993 T992 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 329993 T992 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 329993 T992 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 330016 T992 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 330017 T949 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0
[junit4] 2> 330018 T949 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 330018 T949 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 330323 T949 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 330326 T949 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:17160
[junit4] 2> 330327 T949 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 330327 T949 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 330327 T949 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1376046941421
[junit4] 2> 330328 T949 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1376046941421/'
[junit4] 2> 330370 T949 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1376046941421/solr.xml
[junit4] 2> 330467 T949 oasc.CoreContainer.<init> New CoreContainer 303759318
[junit4] 2> 330467 T949 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1376046941421/]
[junit4] 2> 330469 T949 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 330470 T949 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 330470 T949 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 330470 T949 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 330471 T949 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 330471 T949 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 330472 T949 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 330472 T949 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 330472 T949 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 330473 T949 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 330489 T949 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:17150/solr
[junit4] 2> 330490 T949 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 330491 T949 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 330497 T1005 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2c6edf53 name:ZooKeeperConnection Watcher:127.0.0.1:17150 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 330498 T949 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 330518 T949 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 330525 T949 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 330527 T1007 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@688a7b22 name:ZooKeeperConnection Watcher:127.0.0.1:17150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 330527 T949 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 330537 T949 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 331473 T972 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 331474 T972 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "roles":null,
[junit4] 2> "state":"active",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:17157_",
[junit4] 2> "base_url":"http://127.0.0.1:17157"}
[junit4] 2> 331515 T991 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> 331515 T978 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> 331515 T971 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> 331515 T1007 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> 331540 T949 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:17160_
[junit4] 2> 331542 T949 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:17160_
[junit4] 2> 331544 T991 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 331544 T1007 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 331544 T978 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 331545 T971 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 331545 T978 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 331545 T971 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 331546 T991 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 331546 T1007 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 331557 T1009 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 331557 T1009 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 331559 T1009 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 333020 T972 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 333022 T972 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":null,
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:17160_",
[junit4] 2> "base_url":"http://127.0.0.1:17160"}
[junit4] 2> 333022 T972 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 333022 T972 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 333039 T971 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> 333039 T991 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> 333039 T1007 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> 333039 T978 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> 333561 T1009 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 333561 T1009 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1376046941421/collection1
[junit4] 2> 333561 T1009 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 333562 T1009 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 333562 T1009 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 333563 T1009 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1376046941421/collection1/'
[junit4] 2> 333564 T1009 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1376046941421/collection1/lib/README' to classloader
[junit4] 2> 333564 T1009 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1376046941421/collection1/lib/classes/' to classloader
[junit4] 2> 333602 T1009 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 333641 T1009 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 333742 T1009 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 333749 T1009 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 334214 T1009 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 334228 T1009 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 334232 T1009 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 334248 T1009 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 334253 T1009 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 334257 T1009 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 334258 T1009 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 334258 T1009 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 334259 T1009 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 334260 T1009 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 334260 T1009 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 334260 T1009 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 334261 T1009 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1376046941421/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1376046931370/jetty2/
[junit4] 2> 334261 T1009 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@32b029b6
[junit4] 2> 334262 T1009 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1376046931370/jetty2
[junit4] 2> 334262 T1009 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1376046931370/jetty2/index/
[junit4] 2> 334263 T1009 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1376046931370/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 334263 T1009 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1376046931370/jetty2/index
[junit4] 2> 334267 T1009 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@232d7345 lockFactory=org.apache.lucene.store.NativeFSLockFactory@516dab1b; maxCacheMB=0.76171875 maxMergeSizeMB=0.10546875)),segFN=segments_1,generation=1}
[junit4] 2> 334267 T1009 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 334272 T1009 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 334273 T1009 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 334274 T1009 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 334274 T1009 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 334275 T1009 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 334275 T1009 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 334275 T1009 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 334276 T1009 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 334277 T1009 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 334293 T1009 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 334300 T1009 oass.SolrIndexSearcher.<init> Opening Searcher@587a7ff1 main
[junit4] 2> 334301 T1009 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 334302 T1009 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 334307 T1010 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@587a7ff1 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 334309 T1009 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 334309 T1009 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:17160 collection:collection1 shard:shard1
[junit4] 2> 334310 T1009 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 334329 T1009 oasc.ZkController.register We are http://127.0.0.1:17160/collection1/ and leader is http://127.0.0.1:17157/collection1/
[junit4] 2> 334330 T1009 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:17160
[junit4] 2> 334330 T1009 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 334330 T1009 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C164 name=collection1 org.apache.solr.core.SolrCore@72315f65 url=http://127.0.0.1:17160/collection1 node=127.0.0.1:17160_ C164_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:17160_, base_url=http://127.0.0.1:17160}
[junit4] 2> 334330 T1011 C164 P17160 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 334331 T1009 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 334331 T1011 C164 P17160 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 334331 T1011 C164 P17160 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 334331 T1011 C164 P17160 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 334332 T949 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0
[junit4] 2> 334332 T949 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 334333 T949 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 334333 T1011 C164 P17160 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 334342 T949 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 334343 T981 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> ASYNC NEW_CORE C165 name=collection1 org.apache.solr.core.SolrCore@3255127a url=http://127.0.0.1:17153/collection1 node=127.0.0.1:17153_ C165_STATE=coll:control_collection core:collection1 props:{state=active, core=collection1, node_name=127.0.0.1:17153_, base_url=http://127.0.0.1:17153, leader=true}
[junit4] 2> 334355 T961 C165 P17153 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@1613a15f lockFactory=org.apache.lucene.store.NativeFSLockFactory@6944dc22; maxCacheMB=0.76171875 maxMergeSizeMB=0.10546875)),segFN=segments_1,generation=1}
[junit4] 2> 334356 T961 C165 P17153 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 334359 T962 C165 P17153 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[1 (1442889802182557697)]} 0 6
[junit4] 2> 334359 T961 C165 P17153 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10001 (1442889802182557696)]} 0 6
[junit4] 2> ASYNC NEW_CORE C166 name=collection1 org.apache.solr.core.SolrCore@75a6d5e1 url=http://127.0.0.1:17157/collection1 node=127.0.0.1:17157_ C166_STATE=coll:collection1 core:collection1 props:{state=active, core=collection1, node_name=127.0.0.1:17157_, base_url=http://127.0.0.1:17157, leader=true}
[junit4] 2> 334385 T983 C166 P17157 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@35817d7b lockFactory=org.apache.lucene.store.NativeFSLockFactory@9813867; maxCacheMB=0.76171875 maxMergeSizeMB=0.10546875)),segFN=segments_1,generation=1}
[junit4] 2> 334385 T983 C166 P17157 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 334388 T983 C166 P17157 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10001 (1442889802214014976)]} 0 6
[junit4] 2> 334389 T982 C166 P17157 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[1 (1442889802216112128)]} 0 5
[junit4] 2> 334422 T961 C165 P17153 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10002 (1442889802252812288)]} 0 2
[junit4] 2> 334422 T962 C165 P17153 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[2 (1442889802253860864)]} 0 2
[junit4] 2> 334425 T982 C166 P17157 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10002 (1442889802257006592)]} 0 1
[junit4] 2> 334425 T983 C166 P17157 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[2 (1442889802257006593)]} 0 1
[junit4] 2> 334440 T962 C165 P17153 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10003 (1442889802272735232)]} 0 1
[junit4] 2> 334441 T961 C165 P17153 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[3 (1442889802273783808)]} 0 1
[junit4] 2> 334443 T983 C166 P17157 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10003 (1442889802275880960)]} 0 1
[junit4] 2> 334445 T982 C166 P17157 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[3 (1442889802277978112)]} 0 1
[junit4] 2> 334510 T961 C165 P17153 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10004 (1442889802346135552)]} 0 1
[junit4] 2> 334512 T962 C165 P17153 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[4 (1442889802348232704)]} 0 1
[junit4] 2> 334513 T982 C166 P17157 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10004 (1442889802349281280)]} 0 1
[junit4] 2> 334516 T983 C166 P17157 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[4 (1442889802352427008)]} 0 1
[junit4] 2> 334544 T972 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 334546 T972 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "roles":null,
[junit4] 2> "state":"recovering",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:17160_",
[junit4] 2> "base_url":"http://127.0.0.1:17160"}
[junit4] 2> 334559 T978 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> 334559 T991 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> 334559 T1007 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> 334559 T971 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> 334613 T962 C165 P17153 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10005 (1442889802454138880)]} 0 2
[junit4] 2> 334616 T961 C165 P17153 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[5 (1442889802457284608)]} 0 1
[junit4] 2> C164_STATE=coll:collection1 core:collection1 props:{state=recovering, core=collection1, node_name=127.0.0.1:17160_, base_url=http://127.0.0.1:17160}
[junit4] 2> 334629 T997 C164 P17160 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=BaseDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@232d7345 lockFactory=org.apache.lucene.store.NativeFSLockFactory@516dab1b; maxCacheMB=0.76171875 maxMergeSizeMB=0.10546875)),segFN=segments_1,generation=1}
[junit4] 2> 334629 T997 C164 P17160 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 334633 T998 C164 P17160 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:17157/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[5 (1442889802461478912)]} 0 4
[junit4] 2> 334633 T997 C164 P17160 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:17157/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10005 (1442889802459381760)]} 0 7
[junit4] 2> 334634 T982 C166 P17157 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[5 (1442889802461478912)]} 0 15
[junit4] 2> 334634 T983 C166 P17157 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10005 (1442889802459381760)]} 0 18
[junit4] 2> 334688 T961 C165 P17153 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[4 (-1442889802532782080)]} 0 1
[junit4] 2> 334689 T962 C165 P17153 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10004 (-1442889802534879232)]} 0 1
[junit4] 2> 334701 T998 C164 P17160 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:17157/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10004 (-1442889802539073536)]} 0 1
[junit4] 2> 334702 T997 C164 P17160 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=h
[...truncated too long message...]
... 13 more
[junit4] 2> Caused by: java.lang.ClassNotFoundException: solr.clustering.ClusteringComponent
[junit4] 2> at java.net.URLClassLoader$1.run(URLClassLoader.java:366)
[junit4] 2> at java.net.URLClassLoader$1.run(URLClassLoader.java:355)
[junit4] 2> at java.security.AccessController.doPrivileged(Native Method)
[junit4] 2> at java.net.URLClassLoader.findClass(URLClassLoader.java:354)
[junit4] 2> at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
[junit4] 2> at java.net.FactoryURLClassLoader.loadClass(URLClassLoader.java:789)
[junit4] 2> at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
[junit4] 2> at java.lang.Class.forName0(Native Method)
[junit4] 2> at java.lang.Class.forName(Class.java:270)
[junit4] 2> at org.apache.solr.core.SolrResourceLoader.findClass(SolrResourceLoader.java:433)
[junit4] 2> ... 21 more
[junit4] 2>
[junit4] 2> 2459023 T5245 oas.SolrTestCaseJ4.tearDown ###Ending testDirList
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ShowFileRequestHandlerTest -Dtests.method=testDirList -Dtests.seed=F95BA0F3810C538F -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=ja_JP -Dtests.timezone=America/St_Johns -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.03s J1 | ShowFileRequestHandlerTest.testDirList <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at https://127.0.0.1:57819/solr/collection1 returned non ok status:500, message:{msg=SolrCore 'collection1' is not available due to init failure: Error loading class 'solr.clustering.ClusteringComponent',trace=org.apache.solr.common.SolrException: SolrCore 'collection1' is not available due to init failure: Error loading class 'solr.clustering.ClusteringComponent' at org.apache.solr.core.CoreContainer.getCore(CoreContainer.java:779) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:250) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:158) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419) at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:136) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:455) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229) at org.eclipse.jetty.server.handler.Scope
[junit4] > at __randomizedtesting.SeedInfo.seed([F95BA0F3810C538F:1063B1014952C9B5]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4] > at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:90)
[junit4] > at org.apache.solr.handler.admin.ShowFileRequestHandlerTest.testDirList(ShowFileRequestHandlerTest.java:89)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] 2> 2459030 T5245 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1323539664
[junit4] 2> 2459030 T5245 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 2459083 T5245 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 2459083 T5245 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=140038415
[junit4] 2> 2459083 T5245 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@641494b8
[junit4] 2> 2459094 T5245 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 2459095 T5245 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 2459095 T5245 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 2459095 T5245 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 2459096 T5245 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 2459096 T5245 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 2459096 T5245 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-ShowFileRequestHandlerTest-1376049066489 [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-ShowFileRequestHandlerTest-1376049066489;done=false>>]
[junit4] 2> 2459097 T5245 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-ShowFileRequestHandlerTest-1376049066489
[junit4] 2> 2459097 T5245 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-ShowFileRequestHandlerTest-1376049066489/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-ShowFileRequestHandlerTest-1376049066489/index;done=false>>]
[junit4] 2> 2459097 T5245 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-ShowFileRequestHandlerTest-1376049066489/index
[junit4] 2> NOTE: test params are: codec=Lucene42: {}, docValues:{}, sim=DefaultSimilarity, locale=ja_JP, timezone=America/St_Johns
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=44471608,total=533594112
[junit4] 2> NOTE: All tests run in this JVM: [QueryResultKeyTest, PluginInfoTest, TestRangeQuery, SuggesterTSTTest, TestReloadAndDeleteDocs, NotRequiredUniqueKeyTest, IndexSchemaRuntimeFieldTest, TestCloudManagedSchema, DirectUpdateHandlerTest, DocValuesMultiTest, DirectSolrSpellCheckerTest, SuggesterWFSTTest, DirectSolrConnectionTest, OpenExchangeRatesOrgProviderTest, FullSolrCloudDistribCmdsTest, HdfsSyncSliceTest, IndexBasedSpellCheckerTest, StatsComponentTest, TestLazyCores, TestCSVLoader, RequestHandlersTest, BadCopyFieldTest, SolrCoreCheckLockOnStartupTest, TestAddFieldRealTimeGet, PreAnalyzedFieldTest, TestComponentsName, TestSerializedLuceneMatchVersion, TestSolrDeletionPolicy2, TestSolr4Spatial, CoreContainerCoreInitFailuresTest, SolrCmdDistributorTest, TestRandomMergePolicy, SortByFunctionTest, NoCacheHeaderTest, TestStressRecovery, TestWordDelimiterFilterFactory, TestDistributedGrouping, HdfsRecoveryZkTest, ClusterStateTest, TestFastOutputStream, TestAnalyzedSuggestions, TestPhraseSuggestions, UniqFieldsUpdateProcessorFactoryTest, HdfsLockFactoryTest, TestCoreDiscovery, SolrPluginUtilsTest, DateMathParserTest, SignatureUpdateProcessorFactoryTest, TestArbitraryIndexDir, TestAtomicUpdateErrorCases, TestQueryTypes, TestUpdate, CurrencyFieldXmlFileTest, UUIDFieldTest, LeaderElectionIntegrationTest, XmlUpdateRequestHandlerTest, TestFieldCollectionResource, CircularListTest, OpenCloseCoreStressTest, CoreAdminCreateDiscoverTest, MultiTermTest, PingRequestHandlerTest, TestNumberUtils, BasicZkTest, TestDynamicFieldResource, HighlighterTest, CustomCollectionTest, TestInfoStreamLogging, DebugComponentTest, ZkSolrClientTest, TestXIncludeConfig, JSONWriterTest, BadIndexSchemaTest, TermVectorComponentDistributedTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, SyncSliceTest, TestFaceting, TestRecovery, ZkControllerTest, TestRealTimeGet, TestStressReorder, HardAutoCommitTest, DistributedTermsComponentTest, TestCoreContainer, SimpleFacetsTest, SpellCheckComponentTest, PeerSyncTest, ConvertedLegacyTest, TestSort, TestFiltering, TestBadConfig, ShowFileRequestHandlerTest]
[junit4] Completed on J1 in 4.00s, 4 tests, 1 failure, 2 errors <<< FAILURES!
[...truncated 382 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:396: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:369: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1230: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:873: There were test failures: 318 suites, 1345 tests, 1 suite-level error, 2 errors, 1 failure, 33 ignored (4 assumptions)
Total time: 107 minutes 38 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure