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 2016/01/17 14:51:17 UTC
[JENKINS] Lucene-Solr-NightlyTests-5.4 - Build # 18 - Still Failing
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-5.4/18/
3 tests failed.
FAILED: org.apache.solr.hadoop.MorphlineBasicMiniMRTest.mrRun
Error Message:
Failed on local exception: java.io.IOException: Connection reset by peer; Host Details : local host is: "lucene1-us-west/10.41.0.5"; destination host is: "lucene1-us-west.apache.org":58873;
Stack Trace:
java.io.IOException: Failed on local exception: java.io.IOException: Connection reset by peer; Host Details : local host is: "lucene1-us-west/10.41.0.5"; destination host is: "lucene1-us-west.apache.org":58873;
at __randomizedtesting.SeedInfo.seed([CF4E7F99D80E3DFF:C11CCB97D9980FF0]:0)
at org.apache.hadoop.net.NetUtils.wrapException(NetUtils.java:772)
at org.apache.hadoop.ipc.Client.call(Client.java:1472)
at org.apache.hadoop.ipc.Client.call(Client.java:1399)
at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:232)
at com.sun.proxy.$Proxy45.getClusterMetrics(Unknown Source)
at org.apache.hadoop.yarn.api.impl.pb.client.ApplicationClientProtocolPBClientImpl.getClusterMetrics(ApplicationClientProtocolPBClientImpl.java:202)
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 org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:187)
at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:102)
at com.sun.proxy.$Proxy46.getClusterMetrics(Unknown Source)
at org.apache.hadoop.yarn.client.api.impl.YarnClientImpl.getYarnClusterMetrics(YarnClientImpl.java:461)
at org.apache.hadoop.mapred.ResourceMgrDelegate.getClusterMetrics(ResourceMgrDelegate.java:151)
at org.apache.hadoop.mapred.YARNRunner.getClusterMetrics(YARNRunner.java:179)
at org.apache.hadoop.mapreduce.Cluster.getClusterStatus(Cluster.java:246)
at org.apache.hadoop.mapred.JobClient$3.run(JobClient.java:719)
at org.apache.hadoop.mapred.JobClient$3.run(JobClient.java:717)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:415)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1628)
at org.apache.hadoop.mapred.JobClient.getClusterStatus(JobClient.java:717)
at org.apache.solr.hadoop.MapReduceIndexerTool.run(MapReduceIndexerTool.java:645)
at org.apache.solr.hadoop.MapReduceIndexerTool.run(MapReduceIndexerTool.java:608)
at org.apache.hadoop.util.ToolRunner.run(ToolRunner.java:70)
at org.apache.solr.hadoop.MorphlineBasicMiniMRTest.mrRun(MorphlineBasicMiniMRTest.java:363)
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:1764)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
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:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
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:367)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.io.IOException: Connection reset by peer
at sun.nio.ch.FileDispatcherImpl.write0(Native Method)
at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47)
at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93)
at sun.nio.ch.IOUtil.write(IOUtil.java:65)
at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:492)
at org.apache.hadoop.net.SocketOutputStream$Writer.performIO(SocketOutputStream.java:63)
at org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:142)
at org.apache.hadoop.net.SocketOutputStream.write(SocketOutputStream.java:159)
at org.apache.hadoop.net.SocketOutputStream.write(SocketOutputStream.java:117)
at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
at java.io.DataOutputStream.flush(DataOutputStream.java:123)
at org.apache.hadoop.ipc.Client$Connection$3.run(Client.java:1030)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
... 1 more
FAILED: org.apache.solr.hadoop.MorphlineGoLiveMiniMRTest.test
Error Message:
Failed on local exception: java.io.IOException: Connection reset by peer; Host Details : local host is: "lucene1-us-west/10.41.0.5"; destination host is: "lucene1-us-west.apache.org":44251;
Stack Trace:
java.io.IOException: Failed on local exception: java.io.IOException: Connection reset by peer; Host Details : local host is: "lucene1-us-west/10.41.0.5"; destination host is: "lucene1-us-west.apache.org":44251;
at __randomizedtesting.SeedInfo.seed([CF4E7F99D80E3DFF:471A404376F25007]:0)
at org.apache.hadoop.net.NetUtils.wrapException(NetUtils.java:772)
at org.apache.hadoop.ipc.Client.call(Client.java:1472)
at org.apache.hadoop.ipc.Client.call(Client.java:1399)
at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:232)
at com.sun.proxy.$Proxy47.getClusterMetrics(Unknown Source)
at org.apache.hadoop.yarn.api.impl.pb.client.ApplicationClientProtocolPBClientImpl.getClusterMetrics(ApplicationClientProtocolPBClientImpl.java:202)
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 org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:187)
at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:102)
at com.sun.proxy.$Proxy48.getClusterMetrics(Unknown Source)
at org.apache.hadoop.yarn.client.api.impl.YarnClientImpl.getYarnClusterMetrics(YarnClientImpl.java:461)
at org.apache.hadoop.mapred.ResourceMgrDelegate.getClusterMetrics(ResourceMgrDelegate.java:151)
at org.apache.hadoop.mapred.YARNRunner.getClusterMetrics(YARNRunner.java:179)
at org.apache.hadoop.mapreduce.Cluster.getClusterStatus(Cluster.java:246)
at org.apache.hadoop.mapred.JobClient$3.run(JobClient.java:719)
at org.apache.hadoop.mapred.JobClient$3.run(JobClient.java:717)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:415)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1628)
at org.apache.hadoop.mapred.JobClient.getClusterStatus(JobClient.java:717)
at org.apache.solr.hadoop.MapReduceIndexerTool.run(MapReduceIndexerTool.java:645)
at org.apache.solr.hadoop.MapReduceIndexerTool.run(MapReduceIndexerTool.java:608)
at org.apache.hadoop.util.ToolRunner.run(ToolRunner.java:70)
at org.apache.solr.hadoop.MorphlineGoLiveMiniMRTest.test(MorphlineGoLiveMiniMRTest.java:402)
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:1764)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:964)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:939)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
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:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
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:367)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.io.IOException: Connection reset by peer
at sun.nio.ch.FileDispatcherImpl.read0(Native Method)
at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)
at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)
at sun.nio.ch.IOUtil.read(IOUtil.java:197)
at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:384)
at org.apache.hadoop.net.SocketInputStream$Reader.performIO(SocketInputStream.java:57)
at org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:142)
at org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:161)
at org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:131)
at java.io.FilterInputStream.read(FilterInputStream.java:133)
at java.io.FilterInputStream.read(FilterInputStream.java:133)
at org.apache.hadoop.ipc.Client$Connection$PingInputStream.read(Client.java:513)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
at java.io.BufferedInputStream.read(BufferedInputStream.java:254)
at java.io.DataInputStream.readInt(DataInputStream.java:387)
at org.apache.hadoop.ipc.Client$Connection.receiveRpcResponse(Client.java:1071)
at org.apache.hadoop.ipc.Client$Connection.run(Client.java:966)
FAILED: junit.framework.TestSuite.org.apache.solr.hadoop.MorphlineGoLiveMiniMRTest
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.hadoop.MorphlineGoLiveMiniMRTest: 1) Thread[id=1002, name=Node Status Updater, state=TIMED_WAITING, group=TGRP-MorphlineGoLiveMiniMRTest] at java.lang.Object.wait(Native Method) at org.apache.hadoop.yarn.server.nodemanager.NodeStatusUpdaterImpl$1.run(NodeStatusUpdaterImpl.java:659) at java.lang.Thread.run(Thread.java:745)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.hadoop.MorphlineGoLiveMiniMRTest:
1) Thread[id=1002, name=Node Status Updater, state=TIMED_WAITING, group=TGRP-MorphlineGoLiveMiniMRTest]
at java.lang.Object.wait(Native Method)
at org.apache.hadoop.yarn.server.nodemanager.NodeStatusUpdaterImpl$1.run(NodeStatusUpdaterImpl.java:659)
at java.lang.Thread.run(Thread.java:745)
at __randomizedtesting.SeedInfo.seed([CF4E7F99D80E3DFF]:0)
Build Log:
[...truncated 18283 lines...]
[junit4] Suite: org.apache.solr.hadoop.MorphlineGoLiveMiniMRTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/init-core-data-001
[junit4] 2> 0 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /
[junit4] 2> 2447 WARN (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.NativeCodeLoader Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
[junit4] 1> Formatting using clusterid: testClusterID
[junit4] 2> 2606 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem No KeyProvider found.
[junit4] 2> 2669 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem fsLock is fair:true
[junit4] 2> 2762 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.c.C.deprecation hadoop.configured.node.mapping is deprecated. Instead, use net.topology.configured.node.mapping
[junit4] 2> 2762 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.DatanodeManager dfs.block.invalidate.limit=1000
[junit4] 2> 2763 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.DatanodeManager dfs.namenode.datanode.registration.ip-hostname-check=true
[junit4] 2> 2766 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager dfs.namenode.startup.delay.block.deletion.sec is set to 000:00:00:00.000
[junit4] 2> 2769 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager The block deletion will start around 2016 ene 17 06:17:44
[junit4] 2> 2773 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet Computing capacity for map BlocksMap
[junit4] 2> 2774 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet VM type = 64-bit
[junit4] 2> 2777 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet 2.0% max memory 455 MB = 9.1 MB
[junit4] 2> 2777 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet capacity = 2^20 = 1048576 entries
[junit4] 2> 2805 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager dfs.block.access.token.enable=false
[junit4] 2> 2806 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager defaultReplication = 2
[junit4] 2> 2806 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager maxReplication = 512
[junit4] 2> 2807 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager minReplication = 1
[junit4] 2> 2807 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager maxReplicationStreams = 2
[junit4] 2> 2807 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager shouldCheckForEnoughRacks = false
[junit4] 2> 2808 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager replicationRecheckInterval = 3000
[junit4] 2> 2808 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager encryptDataTransfer = false
[junit4] 2> 2808 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager maxNumBlocksToLog = 1000
[junit4] 2> 2818 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem fsOwner = jenkins (auth:SIMPLE)
[junit4] 2> 2819 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem supergroup = supergroup
[junit4] 2> 2819 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem isPermissionEnabled = true
[junit4] 2> 2820 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem HA Enabled: false
[junit4] 2> 2826 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem Append Enabled: true
[junit4] 2> 3244 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet Computing capacity for map INodeMap
[junit4] 2> 3245 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet VM type = 64-bit
[junit4] 2> 3246 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet 1.0% max memory 455 MB = 4.5 MB
[junit4] 2> 3246 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet capacity = 2^19 = 524288 entries
[junit4] 2> 3247 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.NameNode Caching file names occuring more than 10 times
[junit4] 2> 3264 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet Computing capacity for map cachedBlocks
[junit4] 2> 3264 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet VM type = 64-bit
[junit4] 2> 3265 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet 0.25% max memory 455 MB = 1.1 MB
[junit4] 2> 3265 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet capacity = 2^17 = 131072 entries
[junit4] 2> 3268 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem dfs.namenode.safemode.threshold-pct = 0.9990000128746033
[junit4] 2> 3268 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem dfs.namenode.safemode.min.datanodes = 0
[junit4] 2> 3269 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem dfs.namenode.safemode.extension = 0
[junit4] 2> 3272 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem Retry cache on namenode is enabled
[junit4] 2> 3273 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem Retry cache will use 0.03 of total heap and retry cache entry expiry time is 600000 millis
[junit4] 2> 3279 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet Computing capacity for map NameNodeRetryCache
[junit4] 2> 3280 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet VM type = 64-bit
[junit4] 2> 3280 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet 0.029999999329447746% max memory 455 MB = 139.8 KB
[junit4] 2> 3281 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet capacity = 2^14 = 16384 entries
[junit4] 2> 3314 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.NNConf ACLs enabled? false
[junit4] 2> 3315 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.NNConf XAttrs enabled? true
[junit4] 2> 3315 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.NNConf Maximum size of an xattr: 16384
[junit4] 2> 3417 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSImage Allocated new BlockPoolId: BP-1170593033-10.41.0.5-1453036664718
[junit4] 2> 3444 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.c.Storage Storage directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/name1 has been successfully formatted.
[junit4] 2> 3460 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.c.Storage Storage directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/name2 has been successfully formatted.
[junit4] 2> 3729 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.NNStorageRetentionManager Going to retain 1 images with txid >= 0
[junit4] 2> 3733 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.NameNode createNameNode []
[junit4] 2> 3799 WARN (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.m.i.MetricsConfig Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
[junit4] 2> 3895 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.m.i.MetricsSystemImpl Scheduled snapshot period at 10 second(s).
[junit4] 2> 3895 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.m.i.MetricsSystemImpl NameNode metrics system started
[junit4] 2> 3901 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.NameNode fs.defaultFS is hdfs://127.0.0.1:0
[junit4] 2> 3995 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.DFSUtil Starting Web-server for hdfs at: http://localhost:0
[junit4] 2> 4190 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.m.log Logging to org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via org.mortbay.log.Slf4jLog
[junit4] 2> 4205 WARN (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 4239 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer2$QuotingInputFilter)
[junit4] 2> 4244 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context hdfs
[junit4] 2> 4245 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
[junit4] 2> 4257 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
[junit4] 2> 4330 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 Added filter 'org.apache.hadoop.hdfs.web.AuthFilter' (class=org.apache.hadoop.hdfs.web.AuthFilter)
[junit4] 2> 4333 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 addJerseyResourcePackage: packageName=org.apache.hadoop.hdfs.server.namenode.web.resources;org.apache.hadoop.hdfs.web.resources, pathSpec=/webhdfs/v1/*
[junit4] 2> 4363 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 Jetty bound to port 35845
[junit4] 2> 4363 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 4476 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.m.log Extract jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.6.0-tests.jar!/webapps/hdfs to ./temp/Jetty_localhost_35845_hdfs____f11ltt/webapp
[junit4] 2> 4745 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.m.log NO JSP Support for /, did not find org.apache.jasper.servlet.JspServlet
[junit4] 2> 5913 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:35845
[junit4] 2> 5926 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem No KeyProvider found.
[junit4] 2> 5926 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem fsLock is fair:true
[junit4] 2> 5927 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.DatanodeManager dfs.block.invalidate.limit=1000
[junit4] 2> 5927 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.DatanodeManager dfs.namenode.datanode.registration.ip-hostname-check=true
[junit4] 2> 5928 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager dfs.namenode.startup.delay.block.deletion.sec is set to 000:00:00:00.000
[junit4] 2> 5928 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager The block deletion will start around 2016 ene 17 06:17:47
[junit4] 2> 5928 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet Computing capacity for map BlocksMap
[junit4] 2> 5929 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet VM type = 64-bit
[junit4] 2> 5929 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet 2.0% max memory 455 MB = 9.1 MB
[junit4] 2> 5929 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet capacity = 2^20 = 1048576 entries
[junit4] 2> 5930 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager dfs.block.access.token.enable=false
[junit4] 2> 5930 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager defaultReplication = 2
[junit4] 2> 5931 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager maxReplication = 512
[junit4] 2> 5931 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager minReplication = 1
[junit4] 2> 5931 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager maxReplicationStreams = 2
[junit4] 2> 5931 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager shouldCheckForEnoughRacks = false
[junit4] 2> 5931 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager replicationRecheckInterval = 3000
[junit4] 2> 5931 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager encryptDataTransfer = false
[junit4] 2> 5932 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.b.BlockManager maxNumBlocksToLog = 1000
[junit4] 2> 5932 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem fsOwner = jenkins (auth:SIMPLE)
[junit4] 2> 5932 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem supergroup = supergroup
[junit4] 2> 5932 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem isPermissionEnabled = true
[junit4] 2> 5933 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem HA Enabled: false
[junit4] 2> 5933 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem Append Enabled: true
[junit4] 2> 5934 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet Computing capacity for map INodeMap
[junit4] 2> 5934 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet VM type = 64-bit
[junit4] 2> 5934 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet 1.0% max memory 455 MB = 4.5 MB
[junit4] 2> 5934 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet capacity = 2^19 = 524288 entries
[junit4] 2> 5935 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.NameNode Caching file names occuring more than 10 times
[junit4] 2> 5935 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet Computing capacity for map cachedBlocks
[junit4] 2> 5935 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet VM type = 64-bit
[junit4] 2> 5935 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet 0.25% max memory 455 MB = 1.1 MB
[junit4] 2> 5936 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet capacity = 2^17 = 131072 entries
[junit4] 2> 5936 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem dfs.namenode.safemode.threshold-pct = 0.9990000128746033
[junit4] 2> 5936 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem dfs.namenode.safemode.min.datanodes = 0
[junit4] 2> 5936 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem dfs.namenode.safemode.extension = 0
[junit4] 2> 5936 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem Retry cache on namenode is enabled
[junit4] 2> 5937 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem Retry cache will use 0.03 of total heap and retry cache entry expiry time is 600000 millis
[junit4] 2> 5937 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet Computing capacity for map NameNodeRetryCache
[junit4] 2> 5937 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet VM type = 64-bit
[junit4] 2> 5937 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet 0.029999999329447746% max memory 455 MB = 139.8 KB
[junit4] 2> 5937 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.u.GSet capacity = 2^14 = 16384 entries
[junit4] 2> 5940 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.NNConf ACLs enabled? false
[junit4] 2> 5940 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.NNConf XAttrs enabled? true
[junit4] 2> 5941 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.NNConf Maximum size of an xattr: 16384
[junit4] 2> 5948 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.c.Storage Lock on /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/name1/in_use.lock acquired by nodename 16547@lucene1-us-west
[junit4] 2> 5954 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.c.Storage Lock on /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/name2/in_use.lock acquired by nodename 16547@lucene1-us-west
[junit4] 2> 5959 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FileJournalManager Recovering unfinalized segments in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/name1/current
[junit4] 2> 5959 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FileJournalManager Recovering unfinalized segments in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/name2/current
[junit4] 2> 5960 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSImage No edit log streams selected.
[junit4] 2> 6010 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSImageFormatPBINode Loading 1 INodes.
[junit4] 2> 6025 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSImageFormatProtobuf Loaded FSImage in 0 seconds.
[junit4] 2> 6025 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSImage Loaded image for txid 0 from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/name1/current/fsimage_0000000000000000000
[junit4] 2> 6032 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem Need to save fs image? false (staleImage=false, haEnabled=false, isRollingUpgrade=false)
[junit4] 2> 6033 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSEditLog Starting log segment at 1
[junit4] 2> 6111 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.NameCache initialized with 0 entries 0 lookups
[junit4] 2> 6112 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem Finished loading FSImage in 171 msecs
[junit4] 2> 6493 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.NameNode RPC server is binding to localhost:0
[junit4] 2> 6508 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.i.CallQueueManager Using callQueue class java.util.concurrent.LinkedBlockingQueue
[junit4] 2> 6534 INFO (Socket Reader #1 for port 48961) [ ] o.a.h.i.Server Starting Socket Reader #1 for port 48961
[junit4] 2> 6584 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.NameNode Clients are to use localhost:48961 to access this namenode/service.
[junit4] 2> 6588 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem Registered FSNamesystemState MBean
[junit4] 2> 6606 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem Number of blocks under construction: 0
[junit4] 2> 6606 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem Number of blocks under construction: 0
[junit4] 2> 6607 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem initializing replication queues
[junit4] 2> 6607 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.StateChange STATE* Leaving safe mode after 0 secs
[junit4] 2> 6607 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.StateChange STATE* Network topology has 0 racks and 0 datanodes
[junit4] 2> 6608 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.StateChange STATE* UnderReplicatedBlocks has 0 blocks
[junit4] 2> 6612 INFO (Replication Queue Initializer) [ ] o.a.h.h.s.b.BlockManager Total number of blocks = 0
[junit4] 2> 6613 INFO (Replication Queue Initializer) [ ] o.a.h.h.s.b.BlockManager Number of invalid blocks = 0
[junit4] 2> 6613 INFO (Replication Queue Initializer) [ ] o.a.h.h.s.b.BlockManager Number of under-replicated blocks = 0
[junit4] 2> 6613 INFO (Replication Queue Initializer) [ ] o.a.h.h.s.b.BlockManager Number of over-replicated blocks = 0
[junit4] 2> 6613 INFO (Replication Queue Initializer) [ ] o.a.h.h.s.b.BlockManager Number of blocks being written = 0
[junit4] 2> 6613 INFO (Replication Queue Initializer) [ ] o.a.h.h.StateChange STATE* Replication Queue initialization scan for invalid, over- and under-replicated blocks completed in 6 msec
[junit4] 2> 6677 INFO (IPC Server Responder) [ ] o.a.h.i.Server IPC Server Responder: starting
[junit4] 2> 6681 INFO (IPC Server listener on 48961) [ ] o.a.h.i.Server IPC Server listener on 48961: starting
[junit4] 2> 6686 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.NameNode NameNode RPC up at: localhost/127.0.0.1:48961
[junit4] 2> 6687 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem Starting services required for active state
[junit4] 2> 6701 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Starting CacheReplicationMonitor with interval 30000 milliseconds
[junit4] 2> 6701 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Rescanning after 21496960460 milliseconds
[junit4] 2> 6702 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Scanned 0 directive(s) and 0 block(s) in 1 millisecond(s).
[junit4] 2> 6710 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.MiniDFSCluster Starting DataNode 0 with dfs.datanode.data.dir: [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1,[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2
[junit4] 2> 6807 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.m.i.MetricsSystemImpl DataNode metrics system started (again)
[junit4] 2> 6808 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode Configured hostname is 127.0.0.1
[junit4] 2> 6817 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode Starting DataNode with maxLockedMemory = 0
[junit4] 2> 6827 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode Opened streaming server at /127.0.0.1:48492
[junit4] 2> 6832 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode Balancing bandwith is 1048576 bytes/s
[junit4] 2> 6832 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode Number threads for balancing is 5
[junit4] 2> 6838 WARN (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 6840 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer2$QuotingInputFilter)
[junit4] 2> 6841 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context datanode
[junit4] 2> 6841 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
[junit4] 2> 6841 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
[junit4] 2> 6848 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 addJerseyResourcePackage: packageName=org.apache.hadoop.hdfs.server.datanode.web.resources;org.apache.hadoop.hdfs.web.resources, pathSpec=/webhdfs/v1/*
[junit4] 2> 6849 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 Jetty bound to port 34818
[junit4] 2> 6849 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 6872 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.m.log Extract jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.6.0-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_34818_datanode____.wsrum3/webapp
[junit4] 2> 7018 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.m.log NO JSP Support for /, did not find org.apache.jasper.servlet.JspServlet
[junit4] 2> 36701 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Rescanning after 30000 milliseconds
[junit4] 2> 36702 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Scanned 0 directive(s) and 0 block(s) in 1 millisecond(s).
[junit4] 2> 66701 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Rescanning after 30000 milliseconds
[junit4] 2> 66702 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Scanned 0 directive(s) and 0 block(s) in 1 millisecond(s).
[junit4] 2> 96701 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Rescanning after 30000 milliseconds
[junit4] 2> 96701 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Scanned 0 directive(s) and 0 block(s) in 0 millisecond(s).
[junit4] 2> 126702 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Rescanning after 30001 milliseconds
[junit4] 2> 126702 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Scanned 0 directive(s) and 0 block(s) in 0 millisecond(s).
[junit4] 2> 156703 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Rescanning after 30001 milliseconds
[junit4] 2> 156704 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Scanned 0 directive(s) and 0 block(s) in 1 millisecond(s).
[junit4] 2> 186703 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Rescanning after 30000 milliseconds
[junit4] 2> 186704 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Scanned 0 directive(s) and 0 block(s) in 1 millisecond(s).
[junit4] 2> 216703 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Rescanning after 30000 milliseconds
[junit4] 2> 216704 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Scanned 0 directive(s) and 0 block(s) in 1 millisecond(s).
[junit4] 2> 246704 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Rescanning after 30001 milliseconds
[junit4] 2> 246704 INFO (CacheReplicationMonitor(948290431)) [ ] o.a.h.h.s.b.CacheReplicationMonitor Scanned 0 directive(s) and 0 block(s) in 0 millisecond(s).
[junit4] 2> 261955 WARN (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.m.log EXCEPTION
[junit4] 2> java.net.ConnectException: Connection timed out
[junit4] 2> at java.net.PlainSocketImpl.socketConnect(Native Method)
[junit4] 2> at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
[junit4] 2> at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
[junit4] 2> at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
[junit4] 2> at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
[junit4] 2> at java.net.Socket.connect(Socket.java:579)
[junit4] 2> at java.net.Socket.connect(Socket.java:528)
[junit4] 2> at sun.net.NetworkClient.doConnect(NetworkClient.java:180)
[junit4] 2> at sun.net.www.http.HttpClient.openServer(HttpClient.java:432)
[junit4] 2> at sun.net.www.http.HttpClient.openServer(HttpClient.java:527)
[junit4] 2> at sun.net.www.http.HttpClient.<init>(HttpClient.java:211)
[junit4] 2> at sun.net.www.http.HttpClient.New(HttpClient.java:308)
[junit4] 2> at sun.net.www.http.HttpClient.New(HttpClient.java:326)
[junit4] 2> at sun.net.www.protocol.http.HttpURLConnection.getNewHttpClient(HttpURLConnection.java:997)
[junit4] 2> at sun.net.www.protocol.http.HttpURLConnection.plainConnect(HttpURLConnection.java:933)
[junit4] 2> at sun.net.www.protocol.http.HttpURLConnection.connect(HttpURLConnection.java:851)
[junit4] 2> at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1301)
[junit4] 2> at org.apache.xerces.impl.XMLEntityManager.setupCurrentEntity(Unknown Source)
[junit4] 2> at org.apache.xerces.impl.XMLEntityManager.startEntity(Unknown Source)
[junit4] 2> at org.apache.xerces.impl.XMLEntityManager.startDTDEntity(Unknown Source)
[junit4] 2> at org.apache.xerces.impl.XMLDTDScannerImpl.setInputSource(Unknown Source)
[junit4] 2> at org.apache.xerces.impl.XMLDocumentScannerImpl$DTDDispatcher.dispatch(Unknown Source)
[junit4] 2> at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl.scanDocument(Unknown Source)
[junit4] 2> at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
[junit4] 2> at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
[junit4] 2> at org.apache.xerces.parsers.XMLParser.parse(Unknown Source)
[junit4] 2> at org.apache.xerces.parsers.AbstractSAXParser.parse(Unknown Source)
[junit4] 2> at org.apache.xerces.jaxp.SAXParserImpl$JAXPSAXParser.parse(Unknown Source)
[junit4] 2> at org.apache.xerces.jaxp.SAXParserImpl.parse(Unknown Source)
[junit4] 2> at org.mortbay.xml.XmlParser.parse(XmlParser.java:188)
[junit4] 2> at org.mortbay.xml.XmlParser.parse(XmlParser.java:204)
[junit4] 2> at org.mortbay.jetty.webapp.TagLibConfiguration.configureWebApp(TagLibConfiguration.java:238)
[junit4] 2> at org.mortbay.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1279)
[junit4] 2> at org.mortbay.jetty.handler.ContextHandler.doStart(ContextHandler.java:518)
[junit4] 2> at org.mortbay.jetty.webapp.WebAppContext.doStart(WebAppContext.java:499)
[junit4] 2> at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50)
[junit4] 2> at org.mortbay.jetty.handler.HandlerCollection.doStart(HandlerCollection.java:152)
[junit4] 2> at org.mortbay.jetty.handler.ContextHandlerCollection.doStart(ContextHandlerCollection.java:156)
[junit4] 2> at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50)
[junit4] 2> at org.mortbay.jetty.handler.HandlerWrapper.doStart(HandlerWrapper.java:130)
[junit4] 2> at org.mortbay.jetty.Server.doStart(Server.java:224)
[junit4] 2> at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50)
[junit4] 2> at org.apache.hadoop.http.HttpServer2.start(HttpServer2.java:828)
[junit4] 2> at org.apache.hadoop.hdfs.server.datanode.DataNode.startInfoServer(DataNode.java:663)
[junit4] 2> at org.apache.hadoop.hdfs.server.datanode.DataNode.startDataNode(DataNode.java:1057)
[junit4] 2> at org.apache.hadoop.hdfs.server.datanode.DataNode.<init>(DataNode.java:415)
[junit4] 2> at org.apache.hadoop.hdfs.server.datanode.DataNode.makeInstance(DataNode.java:2268)
[junit4] 2> at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:2155)
[junit4] 2> at org.apache.hadoop.hdfs.MiniDFSCluster.startDataNodes(MiniDFSCluster.java:1443)
[junit4] 2> at org.apache.hadoop.hdfs.MiniDFSCluster.initMiniDFSCluster(MiniDFSCluster.java:828)
[junit4] 2> at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:738)
[junit4] 2> at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:608)
[junit4] 2> at org.apache.solr.hadoop.MorphlineGoLiveMiniMRTest.setupClass(MorphlineGoLiveMiniMRTest.java:183)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:811)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 261966 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:34818
[junit4] 2> 261968 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode dnUserName = jenkins
[junit4] 2> 261969 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode supergroup = supergroup
[junit4] 2> 262002 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.i.CallQueueManager Using callQueue class java.util.concurrent.LinkedBlockingQueue
[junit4] 2> 262003 INFO (Socket Reader #1 for port 38686) [ ] o.a.h.i.Server Starting Socket Reader #1 for port 38686
[junit4] 2> 262018 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode Opened IPC server at /127.0.0.1:38686
[junit4] 2> 262059 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode Refresh request received for nameservices: null
[junit4] 2> 262065 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode Starting BPOfferServices for nameservices: <default>
[junit4] 2> 262084 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.d.DataNode Block pool <registering> (Datanode Uuid unassigned) service to localhost/127.0.0.1:48961 starting to offer service
[junit4] 2> 262095 INFO (IPC Server Responder) [ ] o.a.h.i.Server IPC Server Responder: starting
[junit4] 2> 262098 INFO (IPC Server listener on 38686) [ ] o.a.h.i.Server IPC Server listener on 38686: starting
[junit4] 2> 262111 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.MiniDFSCluster Starting DataNode 1 with dfs.datanode.data.dir: [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data3,[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data4
[junit4] 2> 262139 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.m.i.MetricsSystemImpl DataNode metrics system started (again)
[junit4] 2> 262139 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode Configured hostname is 127.0.0.1
[junit4] 2> 262140 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode Starting DataNode with maxLockedMemory = 0
[junit4] 2> 262141 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode Opened streaming server at /127.0.0.1:40948
[junit4] 2> 262142 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode Balancing bandwith is 1048576 bytes/s
[junit4] 2> 262142 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode Number threads for balancing is 5
[junit4] 2> 262145 WARN (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 262147 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 Added global filter 'safety' (class=org.apache.hadoop.http.HttpServer2$QuotingInputFilter)
[junit4] 2> 262148 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context datanode
[junit4] 2> 262148 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context static
[junit4] 2> 262148 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 Added filter static_user_filter (class=org.apache.hadoop.http.lib.StaticUserWebFilter$StaticUserFilter) to context logs
[junit4] 2> 262151 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 addJerseyResourcePackage: packageName=org.apache.hadoop.hdfs.server.datanode.web.resources;org.apache.hadoop.hdfs.web.resources, pathSpec=/webhdfs/v1/*
[junit4] 2> 262151 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.HttpServer2 Jetty bound to port 56961
[junit4] 2> 262152 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 262182 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.m.log Extract jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.6.0-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_56961_datanode____c64k4a/webapp
[junit4] 2> 262332 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.m.log NO JSP Support for /, did not find org.apache.jasper.servlet.JspServlet
[junit4] 2> 262601 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage DataNode version: -56 and NameNode layout version: -60
[junit4] 2> 262605 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage Lock on /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/in_use.lock acquired by nodename 16547@lucene1-us-west
[junit4] 2> 262607 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage Storage directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1 is not formatted for BP-1170593033-10.41.0.5-1453036664718
[junit4] 2> 262607 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage Formatting ...
[junit4] 2> 262614 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage Lock on /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/in_use.lock acquired by nodename 16547@lucene1-us-west
[junit4] 2> 262615 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage Storage directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2 is not formatted for BP-1170593033-10.41.0.5-1453036664718
[junit4] 2> 262615 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage Formatting ...
[junit4] 2> 262729 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage Analyzing storage directories for bpid BP-1170593033-10.41.0.5-1453036664718
[junit4] 2> 262730 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage Locking is disabled
[junit4] 2> 262732 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage Storage directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/current/BP-1170593033-10.41.0.5-1453036664718 is not formatted.
[junit4] 2> 262732 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage Formatting ...
[junit4] 2> 262733 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage Formatting block pool BP-1170593033-10.41.0.5-1453036664718 directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/current/BP-1170593033-10.41.0.5-1453036664718/current
[junit4] 2> 262736 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage Locking is disabled
[junit4] 2> 262737 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage Storage directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/current/BP-1170593033-10.41.0.5-1453036664718 is not formatted.
[junit4] 2> 262738 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage Formatting ...
[junit4] 2> 262738 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage Formatting block pool BP-1170593033-10.41.0.5-1453036664718 directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/current/BP-1170593033-10.41.0.5-1453036664718/current
[junit4] 2> 262743 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage Restored 0 block files from trash.
[junit4] 2> 262743 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage Restored 0 block files from trash.
[junit4] 2> 262746 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.d.DataNode Setting up storage: nsid=1247913047;bpid=BP-1170593033-10.41.0.5-1453036664718;lv=-56;nsInfo=lv=-60;cid=testClusterID;nsid=1247913047;c=0;bpid=BP-1170593033-10.41.0.5-1453036664718;dnuuid=null
[junit4] 2> 262750 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.d.DataNode Generated and persisted new Datanode UUID c5258e0e-5828-4c50-a699-4fd4ef730d99
[junit4] 2> 262808 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.d.f.i.FsDatasetImpl Added new volume: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/current
[junit4] 2> 262810 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.d.f.i.FsDatasetImpl Added volume - /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/current, StorageType: DISK
[junit4] 2> 262811 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.d.f.i.FsDatasetImpl Added new volume: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/current
[junit4] 2> 262811 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.d.f.i.FsDatasetImpl Added volume - /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/current, StorageType: DISK
[junit4] 2> 262882 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.d.f.i.FsDatasetImpl Registered FSDatasetState MBean
[junit4] 2> 262889 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.d.DirectoryScanner Periodic Directory Tree Verification scan starting at 1453046008266 with interval 21600000
[junit4] 2> 262891 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.d.f.i.FsDatasetImpl Adding block pool BP-1170593033-10.41.0.5-1453036664718
[junit4] 2> 262893 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:56961
[junit4] 2> 262897 INFO (Thread-75) [ ] o.a.h.h.s.d.f.i.FsDatasetImpl Scanning block pool BP-1170593033-10.41.0.5-1453036664718 on volume /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/current...
[junit4] 2> 262901 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode dnUserName = jenkins
[junit4] 2> 262901 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode supergroup = supergroup
[junit4] 2> 262902 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.i.CallQueueManager Using callQueue class java.util.concurrent.LinkedBlockingQueue
[junit4] 2> 262903 INFO (Socket Reader #1 for port 57625) [ ] o.a.h.i.Server Starting Socket Reader #1 for port 57625
[junit4] 2> 262911 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode Opened IPC server at /127.0.0.1:57625
[junit4] 2> 262913 INFO (Thread-77) [ ] o.a.h.h.s.d.f.i.FsDatasetImpl Scanning block pool BP-1170593033-10.41.0.5-1453036664718 on volume /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/current...
[junit4] 2> 262920 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode Refresh request received for nameservices: null
[junit4] 2> 262921 INFO (SUITE-MorphlineGoLiveMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.d.DataNode Starting BPOfferServices for nameservices: <default>
[junit4] 2> 262925 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data3/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data4/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.d.DataNode Block pool <registering> (Datanode Uuid unassigned) service to localhost/127.0.0.1:48961 starting to offer service
[junit4] 2> 262932 INFO (IPC Server Responder) [ ] o.a.h.i.Server IPC Server Responder: starting
[junit4] 2> 262933 INFO (IPC Server listener on 57625) [ ] o.a.h.i.Server IPC Server listener on 57625: starting
[junit4] 2> 262953 INFO (Thread-75) [ ] o.a.h.h.s.d.f.i.FsDatasetImpl Time taken to scan block pool BP-1170593033-10.41.0.5-1453036664718 on /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/current: 50ms
[junit4] 2> 262953 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data3/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data4/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.c.Storage DataNode version: -56 and NameNode layout version: -60
[junit4] 2> 262953 INFO (Thread-77) [ ] o.a.h.h.s.d.f.i.FsDatasetImpl Time taken to scan block pool BP-1170593033-10.41.0.5-1453036664718 on /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/current: 40ms
[junit4] 2> 262955 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.d.f.i.FsDatasetImpl Total time to scan all replicas for block pool BP-1170593033-10.41.0.5-1453036664718: 64ms
[junit4] 2> 262956 INFO (Thread-93) [ ] o.a.h.h.s.d.f.i.FsDatasetImpl Adding replicas to map for block pool BP-1170593033-10.41.0.5-1453036664718 on volume /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/current...
[junit4] 2> 262956 INFO (Thread-94) [ ] o.a.h.h.s.d.f.i.FsDatasetImpl Adding replicas to map for block pool BP-1170593033-10.41.0.5-1453036664718 on volume /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/current...
[junit4] 2> 262957 INFO (Thread-93) [ ] o.a.h.h.s.d.f.i.FsDatasetImpl Time to add replicas to map for block pool BP-1170593033-10.41.0.5-1453036664718 on volume /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/current: 1ms
[junit4] 2> 262957 INFO (Thread-94) [ ] o.a.h.h.s.d.f.i.FsDatasetImpl Time to add replicas to map for block pool BP-1170593033-10.41.0.5-1453036664718 on volume /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/current: 0ms
[junit4] 2> 262957 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data1/, [DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J1/temp/solr.hadoop.MorphlineGoLiveMiniMRTest_CF4E7F99D80E3DFF-001/tempDir-002/hdfs/build/dfs/data/data2/]] heartbeating to localhost/127.0.0.1:48961) [ ] o.a.h.h.s.d.f.i.FsDatasetImpl Total time to add all replicas to map: 1ms
[junit4] 2> 262957 INFO (DataNode: [[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build
[...truncated too long message...]
o.a.h.h.s.b.DecommissionManager Monitor interrupted: java.lang.InterruptedException: sleep interrupted
[junit4] 2> 1931825 INFO (SUITE-MorphlineBasicMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem Stopping services started for active state
[junit4] 2> 1931825 INFO (SUITE-MorphlineBasicMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.h.s.n.FSNamesystem Stopping services started for standby state
[junit4] 2> 1931831 INFO (SUITE-MorphlineBasicMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.m.log Stopped HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:0
[junit4] 2> 1931932 INFO (SUITE-MorphlineBasicMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.m.i.MetricsSystemImpl Stopping JobHistoryServer metrics system...
[junit4] 2> 1931936 ERROR (SUITE-MorphlineBasicMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.m.l.MethodMetric Error invoking method getBlocksTotal
[junit4] 2> java.lang.reflect.InvocationTargetException
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606)
[junit4] 2> at org.apache.hadoop.metrics2.lib.MethodMetric$2.snapshot(MethodMetric.java:111)
[junit4] 2> at org.apache.hadoop.metrics2.lib.MethodMetric.snapshot(MethodMetric.java:144)
[junit4] 2> at org.apache.hadoop.metrics2.lib.MetricsRegistry.snapshot(MetricsRegistry.java:387)
[junit4] 2> at org.apache.hadoop.metrics2.lib.MetricsSourceBuilder$1.getMetrics(MetricsSourceBuilder.java:79)
[junit4] 2> at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.getMetrics(MetricsSourceAdapter.java:195)
[junit4] 2> at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.updateJmxCache(MetricsSourceAdapter.java:172)
[junit4] 2> at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.getMBeanInfo(MetricsSourceAdapter.java:151)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getClassName(DefaultMBeanServerInterceptor.java:1804)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.safeGetClassName(DefaultMBeanServerInterceptor.java:1595)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.checkMBeanPermission(DefaultMBeanServerInterceptor.java:1813)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.exclusiveUnregisterMBean(DefaultMBeanServerInterceptor.java:430)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.unregisterMBean(DefaultMBeanServerInterceptor.java:415)
[junit4] 2> at com.sun.jmx.mbeanserver.JmxMBeanServer.unregisterMBean(JmxMBeanServer.java:546)
[junit4] 2> at org.apache.hadoop.metrics2.util.MBeans.unregister(MBeans.java:81)
[junit4] 2> at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.stopMBeans(MetricsSourceAdapter.java:227)
[junit4] 2> at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.stop(MetricsSourceAdapter.java:212)
[junit4] 2> at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.stopSources(MetricsSystemImpl.java:461)
[junit4] 2> at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.stop(MetricsSystemImpl.java:212)
[junit4] 2> at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.shutdown(MetricsSystemImpl.java:592)
[junit4] 2> at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.shutdownInstance(DefaultMetricsSystem.java:72)
[junit4] 2> at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.shutdown(DefaultMetricsSystem.java:68)
[junit4] 2> at org.apache.hadoop.hdfs.server.namenode.metrics.NameNodeMetrics.shutdown(NameNodeMetrics.java:145)
[junit4] 2> at org.apache.hadoop.hdfs.server.namenode.NameNode.stop(NameNode.java:822)
[junit4] 2> at org.apache.hadoop.hdfs.MiniDFSCluster.shutdown(MiniDFSCluster.java:1720)
[junit4] 2> at org.apache.hadoop.hdfs.MiniDFSCluster.shutdown(MiniDFSCluster.java:1699)
[junit4] 2> at org.apache.solr.hadoop.MorphlineBasicMiniMRTest.teardownClass(MorphlineBasicMiniMRTest.java:195)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:834)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> Caused by: java.lang.NullPointerException
[junit4] 2> at org.apache.hadoop.hdfs.server.blockmanagement.BlocksMap.size(BlocksMap.java:198)
[junit4] 2> at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager.getTotalBlocks(BlockManager.java:3291)
[junit4] 2> at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getBlocksTotal(FSNamesystem.java:6223)
[junit4] 2> ... 53 more
[junit4] 2> 1931952 INFO (SUITE-MorphlineBasicMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.m.i.MetricsSystemImpl JobHistoryServer metrics system stopped.
[junit4] 2> 1931953 INFO (SUITE-MorphlineBasicMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.h.m.i.MetricsSystemImpl JobHistoryServer metrics system shutdown complete.
[junit4] 2> 1931954 INFO (SUITE-MorphlineBasicMiniMRTest-seed#[CF4E7F99D80E3DFF]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-map-reduce/test/J0/temp/solr.hadoop.MorphlineBasicMiniMRTest_CF4E7F99D80E3DFF-001
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=ar_SY, timezone=America/Scoresbysund
[junit4] 2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.7.0_80 (64-bit)/cpus=4,threads=5,free=148964168,total=221249536
[junit4] 2> NOTE: All tests run in this JVM: [MorphlineBasicMiniMRTest]
[junit4] Completed [7/7] on J0 in 1933.17s, 2 tests, 1 error <<< FAILURES!
[...truncated 13 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:799: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:736: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:59: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build.xml:253: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/common-build.xml:467: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/common-build.xml:526: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/common-build.xml:1452: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/common-build.xml:1006: There were test failures: 7 suites, 35 tests, 1 suite-level error, 2 errors, 1 ignored [seed: CF4E7F99D80E3DFF]
Total time: 286 minutes 35 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
No prior successful build to compare, so performing full copy of artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
[JENKINS] Lucene-Solr-NightlyTests-5.4 - Build # 20 - Still Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-5.4/20/
2 tests failed.
FAILED: org.apache.lucene.codecs.simpletext.TestSimpleTextNormsFormat.testNCommonBig
Error Message:
Test abandoned because suite timeout was reached.
Stack Trace:
java.lang.Exception: Test abandoned because suite timeout was reached.
at __randomizedtesting.SeedInfo.seed([45D7D770199B9F72]:0)
FAILED: junit.framework.TestSuite.org.apache.lucene.codecs.simpletext.TestSimpleTextNormsFormat
Error Message:
Suite timeout exceeded (>= 7200000 msec).
Stack Trace:
java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
at __randomizedtesting.SeedInfo.seed([45D7D770199B9F72]:0)
Build Log:
[...truncated 6575 lines...]
[junit4] Suite: org.apache.lucene.codecs.simpletext.TestSimpleTextNormsFormat
[junit4] IGNOR/A 0.14s J0 | TestSimpleTextNormsFormat.testMergeStability
[junit4] > Assumption #1: The MockRandom PF randomizes content on the fly, so we can't check it
[junit4] 2> jan 22, 2016 10:20:30 FM com.carrotsearch.randomizedtesting.ThreadLeakControl$2 evaluate
[junit4] 2> WARNING: Suite execution timed out: org.apache.lucene.codecs.simpletext.TestSimpleTextNormsFormat
[junit4] 2> 1) Thread[id=1, name=main, state=WAITING, group=main]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.lang.Thread.join(Thread.java:1281)
[junit4] 2> at java.lang.Thread.join(Thread.java:1355)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSuite(RandomizedRunner.java:601)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.run(RandomizedRunner.java:450)
[junit4] 2> at com.carrotsearch.ant.tasks.junit4.slave.SlaveMain.execute(SlaveMain.java:244)
[junit4] 2> at com.carrotsearch.ant.tasks.junit4.slave.SlaveMain.main(SlaveMain.java:355)
[junit4] 2> at com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe.main(SlaveMainSafe.java:10)
[junit4] 2> 2) Thread[id=11, name=TEST-TestSimpleTextNormsFormat.testNCommonBig-seed#[45D7D770199B9F72], state=TIMED_WAITING, group=TGRP-TestSimpleTextNormsFormat]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at org.apache.lucene.index.IndexWriter.doWait(IndexWriter.java:4303)
[junit4] 2> at org.apache.lucene.index.IndexWriter.forceMerge(IndexWriter.java:1787)
[junit4] 2> at org.apache.lucene.index.IndexWriter.forceMerge(IndexWriter.java:1721)
[junit4] 2> at org.apache.lucene.index.RandomIndexWriter.forceMerge(RandomIndexWriter.java:412)
[junit4] 2> at org.apache.lucene.index.BaseNormsFormatTestCase.doTestNormsVersusDocValues(BaseNormsFormatTestCase.java:288)
[junit4] 2> at org.apache.lucene.index.BaseNormsFormatTestCase.testNCommonBig(BaseNormsFormatTestCase.java:226)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
[junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 3) Thread[id=8, name=JUnit4-serializer-daemon, state=TIMED_WAITING, group=main]
[junit4] 2> at java.lang.Thread.sleep(Native Method)
[junit4] 2> at com.carrotsearch.ant.tasks.junit4.events.Serializer$1.run(Serializer.java:47)
[junit4] 2> 4) Thread[id=10, name=SUITE-TestSimpleTextNormsFormat-seed#[45D7D770199B9F72], state=RUNNABLE, group=TGRP-TestSimpleTextNormsFormat]
[junit4] 2> at java.lang.Thread.getStackTrace(Thread.java:1589)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$4.run(ThreadLeakControl.java:688)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$4.run(ThreadLeakControl.java:685)
[junit4] 2> at java.security.AccessController.doPrivileged(Native Method)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.getStackTrace(ThreadLeakControl.java:685)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.getThreadsWithTraces(ThreadLeakControl.java:701)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.formatThreadStacksFull(ThreadLeakControl.java:681)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.access$1000(ThreadLeakControl.java:64)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$2.evaluate(ThreadLeakControl.java:414)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSuite(RandomizedRunner.java:681)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.access$200(RandomizedRunner.java:140)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$2.run(RandomizedRunner.java:591)
[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=TestSimpleTextNormsFormat -Dtests.method=testNCommonBig -Dtests.seed=45D7D770199B9F72 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/x1/jenkins/lucene-data/enwiki.random.lines.txt -Dtests.locale=sv_SE -Dtests.timezone=Pacific/Chuuk -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] ERROR 7087s J0 | TestSimpleTextNormsFormat.testNCommonBig <<<
[junit4] > Throwable #1: java.lang.Exception: Test abandoned because suite timeout was reached.
[junit4] > at __randomizedtesting.SeedInfo.seed([45D7D770199B9F72]:0)
[junit4] 2> jan 22, 2016 10:20:30 FM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> jan 22, 2016 10:20:50 FM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> SEVERE: 1 thread leaked from SUITE scope at org.apache.lucene.codecs.simpletext.TestSimpleTextNormsFormat:
[junit4] 2> 1) Thread[id=11, name=TEST-TestSimpleTextNormsFormat.testNCommonBig-seed#[45D7D770199B9F72], state=TIMED_WAITING, group=TGRP-TestSimpleTextNormsFormat]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at org.apache.lucene.index.IndexWriter.doWait(IndexWriter.java:4303)
[junit4] 2> at org.apache.lucene.index.IndexWriter.forceMerge(IndexWriter.java:1787)
[junit4] 2> at org.apache.lucene.index.IndexWriter.forceMerge(IndexWriter.java:1721)
[junit4] 2> at org.apache.lucene.index.RandomIndexWriter.forceMerge(RandomIndexWriter.java:412)
[junit4] 2> at org.apache.lucene.index.BaseNormsFormatTestCase.doTestNormsVersusDocValues(BaseNormsFormatTestCase.java:288)
[junit4] 2> at org.apache.lucene.index.BaseNormsFormatTestCase.testNCommonBig(BaseNormsFormatTestCase.java:226)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
[junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> jan 22, 2016 10:20:50 FM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=11, name=TEST-TestSimpleTextNormsFormat.testNCommonBig-seed#[45D7D770199B9F72], state=TIMED_WAITING, group=TGRP-TestSimpleTextNormsFormat]
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/codecs/test/J0/temp/lucene.codecs.simpletext.TestSimpleTextNormsFormat_45D7D770199B9F72-001
[junit4] 2> Jan 22, 2016 12:20:50 AM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: All leaked threads terminated.
[junit4] 2> NOTE: test params are: codec=SimpleText, sim=DefaultSimilarity, locale=sv_SE, timezone=Pacific/Chuuk
[junit4] 2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.7.0_80 (64-bit)/cpus=4,threads=1,free=107848528,total=285212672
[junit4] 2> NOTE: All tests run in this JVM: [TestSimpleTextNormsFormat]
[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=TestSimpleTextNormsFormat -Dtests.seed=45D7D770199B9F72 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/x1/jenkins/lucene-data/enwiki.random.lines.txt -Dtests.locale=sv_SE -Dtests.timezone=Pacific/Chuuk -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.00s J0 | TestSimpleTextNormsFormat (suite) <<<
[junit4] > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
[junit4] > at __randomizedtesting.SeedInfo.seed([45D7D770199B9F72]:0)
[junit4] Completed [19/21] on J0 in 7220.34s, 16 tests, 2 errors, 1 skipped <<< FAILURES!
[...truncated 18 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:799: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:736: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:59: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build.xml:471: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/common-build.xml:2248: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/module-build.xml:58: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/common-build.xml:1452: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/common-build.xml:1006: There were test failures: 21 suites, 711 tests, 1 suite-level error, 1 error, 1 ignored (1 assumption) [seed: 45D7D770199B9F72]
Total time: 213 minutes 1 second
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
No prior successful build to compare, so performing full copy of artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
[JENKINS] Lucene-Solr-NightlyTests-5.4 - Build # 19 - Still Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-5.4/19/
2 tests failed.
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test
Error Message:
Captured an uncaught exception in thread: Thread[id=57588, name=collection1, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=57588, name=collection1, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:45004: collection already exists: awholynewstresscollection_collection1_0
at __randomizedtesting.SeedInfo.seed([4A69FD110D0318D]:0)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:575)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:241)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:230)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:372)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:325)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1100)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:871)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:807)
at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1574)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1595)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:881)
FAILED: org.apache.solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR
Error Message:
There are still nodes recoverying - waited for 330 seconds
Stack Trace:
java.lang.AssertionError: There are still nodes recoverying - waited for 330 seconds
at __randomizedtesting.SeedInfo.seed([4A69FD110D0318D:DA2CF1AC2B72537E]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:175)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:136)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveriesToFinish(AbstractFullDistribZkTestBase.java:831)
at org.apache.solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR(LeaderInitiatedRecoveryOnShardRestartTest.java:104)
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:1764)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:964)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:939)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
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:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
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:367)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 10575 lines...]
[junit4] Suite: org.apache.solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/init-core-data-001
[junit4] 2> 810505 INFO (SUITE-LeaderInitiatedRecoveryOnShardRestartTest-seed#[4A69FD110D0318D]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /o_pbh/bk
[junit4] 2> 810510 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 810510 INFO (Thread-2212) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 810510 INFO (Thread-2212) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 810610 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.ZkTestServer start zk server on port:34174
[junit4] 2> 810610 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 810611 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 810615 INFO (zkCallback-297-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@1858957f name:ZooKeeperConnection Watcher:127.0.0.1:34174 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 810615 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 810615 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 810616 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 810619 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 810620 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 810622 INFO (zkCallback-298-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@429e89ff name:ZooKeeperConnection Watcher:127.0.0.1:34174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 810622 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 810622 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 810622 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1
[junit4] 2> 810625 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/shards
[junit4] 2> 810627 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection
[junit4] 2> 810628 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/shards
[junit4] 2> 810630 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 810630 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 810633 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 810633 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/schema.xml
[junit4] 2> 810635 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 810635 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 810637 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 810638 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/stopwords.txt
[junit4] 2> 810639 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 810639 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/protwords.txt
[junit4] 2> 810641 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 810641 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/currency.xml
[junit4] 2> 810643 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 810643 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 810645 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 810645 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 810647 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 810647 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 810648 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 810649 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 810650 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 810650 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/synonyms.txt
[junit4] 2> 810747 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001/cores/collection1
[junit4] 2> 810748 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.e.j.s.Server jetty-9.2.13.v20150730
[junit4] 2> 810750 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@61eda475{/o_pbh/bk,null,AVAILABLE}
[junit4] 2> 810754 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.e.j.s.ServerConnector Started ServerConnector@5ea9ef1a{HTTP/1.1}{127.0.0.1:58201}
[junit4] 2> 810754 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.e.j.s.Server Started @814300ms
[junit4] 2> 810754 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/tempDir-001/control/data, hostPort=58201, hostContext=/o_pbh/bk, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001/cores}
[junit4] 2> 810755 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@4f6de641
[junit4] 2> 810755 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001'
[junit4] 2> 810755 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 810755 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 810755 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 810756 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 810757 INFO (zkCallback-299-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6c45da4f name:ZooKeeperConnection Watcher:127.0.0.1:34174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 810757 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 810758 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 810759 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 810759 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001/solr.xml
[junit4] 2> 810774 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.CorePropertiesLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001/cores
[junit4] 2> 810775 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.CoreContainer New CoreContainer 813601407
[junit4] 2> 810775 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001]
[junit4] 2> 810775 WARN (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.CoreContainer Couldn't add files from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001/lib to classpath: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001/lib
[junit4] 2> 810775 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.h.c.HttpShardHandlerFactory created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
[junit4] 2> 810776 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 810777 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 810777 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 810777 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34174/solr
[junit4] 2> 810777 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.ZkController zkHost includes chroot
[junit4] 2> 810777 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 810778 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 810779 INFO (zkCallback-301-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@4af6ea8f name:ZooKeeperConnection Watcher:127.0.0.1:34174 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 810780 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 810780 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 810782 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 810784 INFO (zkCallback-302-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@40183543 name:ZooKeeperConnection Watcher:127.0.0.1:34174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 810785 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 810786 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue
[junit4] 2> 810788 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work
[junit4] 2> 810791 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running
[junit4] 2> 810793 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed
[junit4] 2> 810795 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure
[junit4] 2> 810797 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 810799 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 810800 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 810801 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.SolrZkClient makePath: /security.json
[junit4] 2> 810802 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58201_o_pbh%2Fbk
[junit4] 2> 810802 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:58201_o_pbh%2Fbk
[junit4] 2> 810804 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect
[junit4] 2> 810806 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election
[junit4] 2> 810807 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 810808 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/95234788037099524-127.0.0.1:58201_o_pbh%2Fbk-n_0000000000
[junit4] 2> 810808 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:58201_o_pbh%2Fbk
[junit4] 2> 810808 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader
[junit4] 2> 810809 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.Overseer Overseer (id=95234788037099524-127.0.0.1:58201_o_pbh%2Fbk-n_0000000000) starting
[junit4] 2> 810811 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work
[junit4] 2> 810818 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 810819 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 810819 INFO (OverseerCollectionConfigSetProcessor-95234788037099524-127.0.0.1:58201_o_pbh%2Fbk-n_0000000000) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations
[junit4] 2> 810819 INFO (OverseerStateUpdate-95234788037099524-127.0.0.1:58201_o_pbh%2Fbk-n_0000000000) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 810842 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
[junit4] 2> 810842 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.CoreContainer No authentication plugin used.
[junit4] 2> 810843 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.CorePropertiesLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001/cores
[junit4] 2> 810844 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.CoreDescriptor Created CoreDescriptor: {configSetProperties=configsetprops.json, dataDir=data/, shard=, name=collection1, absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001/cores/collection1/, collection=control_collection, schema=schema.xml, config=solrconfig.xml, transient=false, loadOnStartup=true, coreNodeName=, instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001/cores/collection1}
[junit4] 2> 810844 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.CorePropertiesLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001/cores/collection1/
[junit4] 2> 810844 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.CorePropertiesLocator Found 1 core definitions
[junit4] 2> 810845 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2
[junit4] 2> 810845 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
[junit4] 2> 810846 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.c.ZkController publishing state=down
[junit4] 2> 810846 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
[junit4] 2> 810848 INFO (OverseerStateUpdate-95234788037099524-127.0.0.1:58201_o_pbh%2Fbk-n_0000000000) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"state",
[junit4] 2> "roles":null,
[junit4] 2> "shard":null,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":"127.0.0.1:58201_o_pbh%2Fbk",
[junit4] 2> "base_url":"http://127.0.0.1:58201/o_pbh/bk",
[junit4] 2> "numShards":"1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "core":"collection1"} current state version: 0
[junit4] 2> 810848 INFO (OverseerStateUpdate-95234788037099524-127.0.0.1:58201_o_pbh%2Fbk-n_0000000000) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "roles":null,
[junit4] 2> "shard":null,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":"127.0.0.1:58201_o_pbh%2Fbk",
[junit4] 2> "base_url":"http://127.0.0.1:58201/o_pbh/bk",
[junit4] 2> "numShards":"1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "core":"collection1"}
[junit4] 2> 810849 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.c.ZkController look for our core node name
[junit4] 2> 810849 INFO (OverseerStateUpdate-95234788037099524-127.0.0.1:58201_o_pbh%2Fbk-n_0000000000) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.o.ClusterStateMutator building a new cName: control_collection
[junit4] 2> 810849 INFO (OverseerStateUpdate-95234788037099524-127.0.0.1:58201_o_pbh%2Fbk-n_0000000000) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 810851 INFO (zkCallback-302-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 811849 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1
[junit4] 2> 811849 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.c.ZkController Check for collection zkNode:control_collection
[junit4] 2> 811850 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.c.ZkController Collection zkNode exists
[junit4] 2> 811850 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/control_collection
[junit4] 2> 811851 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.c.c.ZkStateReader path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 811851 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001/cores/collection1'
[junit4] 2> 811851 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 811851 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 811853 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.c.Config loaded config solrconfig.xml with version 0
[junit4] 2> 811865 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
[junit4] 2> 811880 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.4.1
[junit4] 2> 811921 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
[junit4] 2> 811929 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 812175 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 812182 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.s.IndexSchema default search field in schema is text
[junit4] 2> 812184 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.s.IndexSchema unique key field: id
[junit4] 2> 812193 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 812196 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 812201 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 812202 WARN (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
[junit4] 2> 812202 WARN (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
[junit4] 2> 812202 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 812203 WARN (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
[junit4] 2> 812203 WARN (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
[junit4] 2> 812204 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default properties: Can't find resource 'configsetprops.json' in classpath or '/configs/conf1', cwd=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2
[junit4] 2> 812204 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 812205 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 812205 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001/cores/collection1], dataDir=[null]
[junit4] 2> 812205 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@74e6cbcd
[junit4] 2> 812206 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001/cores/collection1/data
[junit4] 2> 812206 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001/cores/collection1/data/index/
[junit4] 2> 812206 WARN (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Solr index directory '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001/cores/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 812206 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001/cores/collection1/data/index
[junit4] 2> 812206 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=7, maxMergeAtOnceExplicit=5, maxMergedSegmentMB=90.5849609375, floorSegmentMB=0.525390625, forceMergeDeletesPctAllowed=13.990931011606547, segmentsPerTier=22.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4311583666984832
[junit4] 2> 812207 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=RawDirectoryWrapper(RAMDirectory@f28f07b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@48c42303),segFN=segments_1,generation=1}
[junit4] 2> 812207 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 812207 INFO (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Looking for old index directories to cleanup for core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001/cores/collection1/data/
[junit4] 2> 812208 WARN (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.DirectoryFactory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/control-001/cores/collection1/data/ does not point to a valid data directory; skipping clean-up of old index directories.
[junit4] 2> 812212 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 812212 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
[junit4] 2> 812212 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 812212 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 812212 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 812212 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 812212 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 812213 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 812213 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 812213 WARN (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,args = {defaults={a=A,b=B}}}
[junit4] 2> 812216 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 812217 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 812218 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 812219 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 812223 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/logging,/admin/ping,/admin/segments,/admin/plugins,standard,/admin/file,/replication,/admin/system,/config,/admin/mbeans,/dump,/update/json,/update,/update/csv,/schema,/update/json/docs,/get,/admin/threads,/admin/luke,/admin/properties
[junit4] 2> 812225 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
[junit4] 2> 812225 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 812225 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 812226 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 812226 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 812226 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1648139133, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 812227 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=RawDirectoryWrapper(RAMDirectory@f28f07b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@48c42303),segFN=segments_1,generation=1}
[junit4] 2> 812227 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 812227 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@633f647d[collection1] main
[junit4] 2> 812227 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/control_collection
[junit4] 2> 812228 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.ZkStateReader path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 812228 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 812228 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 812228 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {}
[junit4] 2> 812228 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 812229 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 812229 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 812229 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
[junit4] 2> 812229 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 812230 INFO (searcherExecutor-1497-thread-1-processing-r:core_node1 s:shard1 n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@633f647d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 812230 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Looking up max value of version field to seed version buckets
[junit4] 2> 812230 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.VersionInfo Refreshing highest value of _version_ for 65536 version buckets from index
[junit4] 2> 812230 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.VersionInfo No terms found for _version_, cannot seed version bucket highest value from index
[junit4] 2> 812230 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1523756610396094464
[junit4] 2> 812232 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Took 2.0ms to seed version buckets with highest version 1523756610396094464
[junit4] 2> 812232 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController watch zkdir /configs/conf1
[junit4] 2> 812233 INFO (coreLoadExecutor-1496-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CoreContainer registering core: collection1
[junit4] 2> 812233 INFO (coreZkRegister-1490-thread-1-processing-r:core_node1 s:shard1 n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController Register replica - core:collection1 address:http://127.0.0.1:58201/o_pbh/bk collection:control_collection shard:shard1
[junit4] 2> 812234 INFO (coreZkRegister-1490-thread-1-processing-r:core_node1 s:shard1 n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 812237 INFO (coreZkRegister-1490-thread-1-processing-r:core_node1 s:shard1 n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.LeaderElector Joined leadership election with path: /collections/control_collection/leader_elect/shard1/election/95234788037099524-core_node1-n_0000000000
[junit4] 2> 812237 INFO (coreZkRegister-1490-thread-1-processing-r:core_node1 s:shard1 n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Running the leader process for shard shard1
[junit4] 2> 812239 INFO (coreZkRegister-1490-thread-1-processing-r:core_node1 s:shard1 n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 812239 INFO (coreZkRegister-1490-thread-1-processing-r:core_node1 s:shard1 n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 812239 INFO (coreZkRegister-1490-thread-1-processing-r:core_node1 s:shard1 n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:58201/o_pbh/bk/collection1/
[junit4] 2> 812239 INFO (coreZkRegister-1490-thread-1-processing-r:core_node1 s:shard1 n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 812239 INFO (coreZkRegister-1490-thread-1-processing-r:core_node1 s:shard1 n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:58201/o_pbh/bk/collection1/ has no replicas
[junit4] 2> 812239 INFO (OverseerStateUpdate-95234788037099524-127.0.0.1:58201_o_pbh%2Fbk-n_0000000000) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection"} current state version: 1
[junit4] 2> 812240 INFO (coreZkRegister-1490-thread-1-processing-r:core_node1 s:shard1 n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 812243 INFO (coreZkRegister-1490-thread-1-processing-r:core_node1 s:shard1 n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node
[junit4] 2> 812245 INFO (coreZkRegister-1490-thread-1-processing-r:core_node1 s:shard1 n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:58201/o_pbh/bk/collection1/ shard1
[junit4] 2> 812245 INFO (OverseerStateUpdate-95234788037099524-127.0.0.1:58201_o_pbh%2Fbk-n_0000000000) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "base_url":"http://127.0.0.1:58201/o_pbh/bk",
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"active"} current state version: 1
[junit4] 2> 812347 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 812348 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 812349 INFO (zkCallback-302-thread-1-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 812350 INFO (zkCallback-304-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@11f8d9eb name:ZooKeeperConnection Watcher:127.0.0.1:34174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 812350 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 812350 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 812350 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 812353 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 812396 INFO (coreZkRegister-1490-thread-1-processing-r:core_node1 s:shard1 n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController We are http://127.0.0.1:58201/o_pbh/bk/collection1/ and leader is http://127.0.0.1:58201/o_pbh/bk/collection1/
[junit4] 2> 812396 INFO (coreZkRegister-1490-thread-1-processing-r:core_node1 s:shard1 n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58201/o_pbh/bk
[junit4] 2> 812396 INFO (coreZkRegister-1490-thread-1-processing-r:core_node1 s:shard1 n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 812396 INFO (coreZkRegister-1490-thread-1-processing-r:core_node1 s:shard1 n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController publishing state=active
[junit4] 2> 812396 INFO (coreZkRegister-1490-thread-1-processing-r:core_node1 s:shard1 n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection x:collection1) [n:127.0.0.1:58201_o_pbh%2Fbk c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
[junit4] 2> 812399 INFO (OverseerStateUpdate-95234788037099524-127.0.0.1:58201_o_pbh%2Fbk-n_0000000000) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"state",
[junit4] 2> "roles":null,
[junit4] 2> "shard":"shard1",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1:58201_o_pbh%2Fbk",
[junit4] 2> "base_url":"http://127.0.0.1:58201/o_pbh/bk",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "core":"collection1"} current state version: 2
[junit4] 2> 812399 INFO (OverseerStateUpdate-95234788037099524-127.0.0.1:58201_o_pbh%2Fbk-n_0000000000) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "roles":null,
[junit4] 2> "shard":"shard1",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1:58201_o_pbh%2Fbk",
[junit4] 2> "base_url":"http://127.0.0.1:58201/o_pbh/bk",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "core":"collection1"}
[junit4] 2> 812451 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/shard-1-001/cores/collection1
[junit4] 2> 812452 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/shard-1-001
[junit4] 2> 812452 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.e.j.s.Server jetty-9.2.13.v20150730
[junit4] 2> 812454 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6ec5f7c1{/o_pbh/bk,null,AVAILABLE}
[junit4] 2> 812455 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.e.j.s.ServerConnector Started ServerConnector@5c681ba5{HTTP/1.1}{127.0.0.1:44359}
[junit4] 2> 812455 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.e.j.s.Server Started @816001ms
[junit4] 2> 812455 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/o_pbh/bk, solrconfig=solrconfig.xml, hostPort=44359, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/shard-1-001/cores, solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/tempDir-001/jetty1}
[junit4] 2> 812455 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@4f6de641
[junit4] 2> 812455 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/shard-1-001'
[junit4] 2> 812456 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 812456 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 812456 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 812457 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 812458 INFO (zkCallback-305-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@645c661b name:ZooKeeperConnection Watcher:127.0.0.1:34174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 812458 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 812459 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 812460 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 812460 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/shard-1-001/solr.xml
[junit4] 2> 812476 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.CorePropertiesLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/shard-1-001/cores
[junit4] 2> 812476 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.CoreContainer New CoreContainer 667384420
[junit4] 2> 812476 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/shard-1-001]
[junit4] 2> 812476 WARN (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.CoreContainer Couldn't add files from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/shard-1-001/lib to classpath: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/shard-1-001/lib
[junit4] 2> 812476 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.h.c.HttpShardHandlerFactory created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
[junit4] 2> 812478 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 812478 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 812478 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 812478 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34174/solr
[junit4] 2> 812478 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.ZkController zkHost includes chroot
[junit4] 2> 812478 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 812479 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 812480 INFO (zkCallback-307-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@26c49e74 name:ZooKeeperConnection Watcher:127.0.0.1:34174 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 812481 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 812481 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 812484 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 812485 INFO (zkCallback-308-thread-1-processing-n:127.0.0.1:44359_o_pbh%2Fbk) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@51fff0c0 name:ZooKeeperConnection Watcher:127.0.0.1:34174/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 812485 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 812490 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 812502 INFO (zkCallback-304-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 812502 INFO (zkCallback-302-thread-2-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 812502 INFO (zkCallback-308-thread-1-processing-n:127.0.0.1:44359_o_pbh%2Fbk) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 813496 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44359_o_pbh%2Fbk
[junit4] 2> 813497 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:44359_o_pbh%2Fbk
[junit4] 2> 813498 INFO (zkCallback-304-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 813498 INFO (zkCallback-302-thread-2-processing-n:127.0.0.1:58201_o_pbh%2Fbk) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 813498 INFO (zkCallback-308-thread-1-processing-n:127.0.0.1:44359_o_pbh%2Fbk) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 813500 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 813500 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/95234788037099528-127.0.0.1:44359_o_pbh%2Fbk-n_0000000001
[junit4] 2> 813501 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/95234788037099524-127.0.0.1:58201_o_pbh%2Fbk-n_0000000000 to know if I could be the leader
[junit4] 2> 813523 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
[junit4] 2> 813523 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.c.CoreContainer No authentication plugin used.
[junit4] 2> 813525 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.c.CorePropertiesLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/shard-1-001/cores
[junit4] 2> 813526 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.c.CoreDescriptor Created CoreDescriptor: {loadOnStartup=true, name=collection1, configSetProperties=configsetprops.json, dataDir=data/, config=solrconfig.xml, shard=, collection=collection1, transient=false, coreNodeName=, instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/shard-1-001/cores/collection1, schema=schema.xml, absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/shard-1-001/cores/collection1/}
[junit4] 2> 813526 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.c.CorePropertiesLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_4A69FD110D0318D-001/shard-1-001/cores/collection1/
[junit4] 2> 813527 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.c.CorePropertiesLocator Found 1 core definitions
[junit4] 2> 813529 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2
[junit4] 2> 813530 INFO (coreLoadExecutor-1507-thread-1-processing-n:127.0.0.1:44359_o_pbh%2Fbk) [n:127.0.0.1:44359_o_pbh%2Fbk c:collection1 x:collection1] o.a.s.c.ZkController publishing state=down
[junit4] 2> 813530 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[4A69FD110D0318D]) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
[junit4] 2> 813530 INFO (coreLoadExecutor-1507-thread-1-processing-n:127.0.0.1:44359_o_pbh%2Fbk) [n:127.0.0.1:44359_o_pbh%2Fbk c:collection1 x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
[junit4] 2> 813532 INFO (OverseerStateUpdate-95234788037099524-127.0.0.1:58201_o_pbh%2Fbk-n_0000000000) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"state",
[junit4] 2> "roles":null,
[junit4] 2> "shard":null,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":"127.0.0.1:44359_o_pbh%2Fbk",
[junit4] 2> "base_url":"http://127.0.0.1:44359/o_pbh/bk",
[junit4] 2> "numShards":"1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"collection1"} current state version: 3
[junit4] 2> 813532 INFO (OverseerStateUpdate-95234788037099524-127.0.0.1:58201_o_pbh%2Fbk-n_0000000000) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "roles":null,
[junit4] 2> "shard":null,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":"127.0.0.1:44359_o_pbh%2Fbk",
[junit4] 2> "base_url":"http://127.0.0.1:44359/o_pbh/bk",
[junit4] 2> "numShards":"1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"collection1"}
[junit4] 2> 813533 INFO (OverseerStateUpdate-95234788037099524-127.0.0.1:58201_o_pbh%2Fbk-n_0000000000) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1
[junit4] 2> 813533 INFO (OverseerStateUpdate-95234788037099524-127.0.0.1:58201_o_pbh%2Fbk-n_0000000000) [n:127.0.0.1:58201_o_pbh%2Fbk ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 813534 INFO (coreLoadExecutor-1507-thread-1-processing-n:127.0.0.1:44359_o_pbh%2Fbk) [n:127.0.0.1:44359_o_pbh%2Fbk c:collection1 x:collection1] o.a.s.c.ZkController look for our core node name
[junit4] 2> 813636 INFO (zkCallback-304-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 813636 INFO (zkCallback-308-thread-1-processing-n:127.0.0.1:44359_o_pbh%2Fbk) [n:127.0.0.1:44359_o_pbh%2Fbk ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged
[...truncated too long message...]
collection already exists: awholynewstresscollection_collection2_0
[junit4] > at __randomizedtesting.SeedInfo.seed([4A69FD110D0318D]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:575)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:241)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:230)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:372)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:325)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1100)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:871)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:807)
[junit4] > at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1574)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1595)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:881)Throwable #4: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=57587, name=collection0, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
[junit4] > Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:45004: collection already exists: awholynewstresscollection_collection0_0
[junit4] > at __randomizedtesting.SeedInfo.seed([4A69FD110D0318D]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:575)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:241)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:230)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:372)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:325)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1100)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:871)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:807)
[junit4] > at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1574)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1595)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:881)Throwable #5: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=57591, name=collection4, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
[junit4] > Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:45004: Could not find collection : awholynewstresscollection_collection4_0
[junit4] > at __randomizedtesting.SeedInfo.seed([4A69FD110D0318D]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:575)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:241)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:230)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:372)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:325)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1100)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:871)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:807)
[junit4] > at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:888)
[junit4] 2> 3492316 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[4A69FD110D0318D]-worker) [n:127.0.0.1:56469_ c:addReplicaColl s:shard1 r:core_node2 x:addReplicaColl_shard1_replica1] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene54): {a_i1=PostingsFormat(name=Direct), a_t=PostingsFormat(name=Direct), multiDefault=PostingsFormat(name=Direct), range_facet_l=PostingsFormat(name=Direct), text=PostingsFormat(name=MockRandom), range_facet_i_dv=PostingsFormat(name=Direct), range_facet_l_dv=FST50, other_tl1=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), _version_=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), timestamp=PostingsFormat(name=Direct), intDefault=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), id=FST50}, docValues:{range_facet_i_dv=DocValuesFormat(name=Lucene54), range_facet_l_dv=DocValuesFormat(name=Memory), timestamp=DocValuesFormat(name=Lucene54)}, sim=DefaultSimilarity, locale=sr_RS_#Latn, timezone=Iceland
[junit4] 2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.7.0_80 (64-bit)/cpus=4,threads=1,free=226692200,total=482344960
[junit4] 2> NOTE: All tests run in this JVM: [TestSolr4Spatial, TestIBSimilarityFactory, DocumentAnalysisRequestHandlerTest, DeleteLastCustomShardedReplicaTest, TestSchemaManager, FileBasedSpellCheckerTest, TestSmileRequest, TestSimpleTrackingShardHandler, DefaultValueUpdateProcessorTest, ChangedSchemaMergeTest, ConnectionManagerTest, VMParamsZkACLAndCredentialsProvidersTest, StandardRequestHandlerTest, ExitableDirectoryReaderTest, AnalyticsMergeStrategyTest, DeleteShardTest, PeerSyncTest, DeleteInactiveReplicaTest, ReplicationFactorTest, EnumFieldTest, TestOmitPositions, AlternateDirectoryTest, TestSortByMinMaxFunction, TestRTGBase, TestFieldSortValues, QueryElevationComponentTest, DistributedFacetPivotSmallAdvancedTest, TestConfigSetsAPIExclusivity, PrimUtilsTest, OverseerCollectionConfigSetProcessorTest, TestCustomSort, TestDistributedSearch, TestReloadAndDeleteDocs, JsonLoaderTest, TestLRUCache, HdfsRecoveryZkTest, ParsingFieldUpdateProcessorsTest, TestEmbeddedSolrServerConstructors, TestSolrConfigHandler, TestShortCircuitedRequests, TestMacros, AnalysisAfterCoreReloadTest, IndexSchemaTest, DocValuesMissingTest, PolyFieldTest, IndexSchemaRuntimeFieldTest, QueryEqualityTest, TestPivotHelperCode, TestRawResponseWriter, DistribJoinFromCollectionTest, TestRandomFaceting, HdfsDirectoryFactoryTest, TestDynamicLoading, TestDocBasedVersionConstraints, URLClassifyProcessorTest, HdfsWriteToMultipleCollectionsTest, CachingDirectoryFactoryTest, XsltUpdateRequestHandlerTest, TestRangeQuery, ZkStateReaderTest, TestSchemaSimilarityResource, PingRequestHandlerTest, TestLMDirichletSimilarityFactory, TestRandomDVFaceting, ZkStateWriterTest, SolrRequestParserTest, TestRandomMergePolicy, TestBinaryField, TestFaceting, TestCSVLoader, TestValueSourceCache, TestInitParams, PreAnalyzedFieldTest, SynonymTokenizerTest, SignatureUpdateProcessorFactoryTest, TestLazyCores, TestManagedSynonymFilterFactory, SegmentsInfoRequestHandlerTest, CollectionReloadTest, TestExceedMaxTermLength, TestNRTOpen, TestShardHandlerFactory, TestReqParamsAPI, HdfsDirectoryTest, TestUniqueKeyFieldResource, RAMDirectoryFactoryTest, TestDynamicFieldCollectionResource, TestPseudoReturnFields, TestComponentsName, TestAuthorizationFramework, DistributedSpellCheckComponentTest, CollectionsAPIDistributedZkTest]
[junit4] Completed [253/551] on J0 in 385.39s, 1 test, 1 error <<< FAILURES!
[...truncated 1016 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:799: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:736: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:59: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build.xml:233: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/common-build.xml:526: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/common-build.xml:1452: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/common-build.xml:1006: There were test failures: 551 suites (7 ignored), 2179 tests, 1 error, 1 failure, 32 ignored (18 assumptions) [seed: 4A69FD110D0318D]
Total time: 264 minutes 31 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
No prior successful build to compare, so performing full copy of artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any