You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2018/01/02 13:20:45 UTC
[JENKINS] Lucene-Solr-master-MacOSX (64bit/jdk1.8.0) - Build # 4360
- Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/4360/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseG1GC
2 tests failed.
FAILED: org.apache.solr.ltr.TestLTRQParserExplain.testRerankedExplainSameBetweenDifferentDocsWithSameFeatures
Error Message:
mismatch: ' 3.5116758 = LinearModel(name=6029760550880411648,featureWeights=[title=0.0,description=0.1,keywords=0.2,popularity=0.3,text=0.4,queryIntentPerson=0.1231231,queryIntentCompany=0.12121211]) model applied to features, sum of: 0.0 = prod of: 0.0 = weight on feature 1.0 = ValueFeature [name=title, params={value=1}] 0.2 = prod of: 0.1 = weight on feature 2.0 = ValueFeature [name=description, params={value=2}] 0.4 = prod of: 0.2 = weight on feature 2.0 = ValueFeature [name=keywords, params={value=2}] 0.09 = prod of: 0.3 = weight on feature 0.3 = normalized using MinMaxNormalizer(min=0.0,max=10.0) 3.0 = ValueFeature [name=popularity, params={value=3}] 1.6 = prod of: 0.4 = weight on feature 4.0 = ValueFeature [name=text, params={value=4}] 0.6156155 = prod of: 0.1231231 = weight on feature 5.0 = ValueFeature [name=queryIntentPerson, params={value=5}] 0.60606056 = prod of: 0.12121211 = weight on feature 5.0 = ValueFeature [name=queryIntentCompany, params={value=5}] '!=' 3.5116758 = LinearModel(name=6029760550880411648,featureWeights=[title=0.0,description=0.1,keywords=0.2,popularity=0.3,text=0.4,queryIntentPerson=0.1231231,queryIntentCompany=0.12121211]) model applied to features, sum of: 0.0 = prod of: 0.0 = weight on feature 1.0 = ValueFeature [name=title, params={value=1}] 0.20000000298023224 = prod of: 0.1 = weight on feature 2.0 = ValueFeature [name=description, params={value=2}] 0.4000000059604645 = prod of: 0.2 = weight on feature 2.0 = ValueFeature [name=keywords, params={value=2}] 0.09000000715255752 = prod of: 0.3 = weight on feature 0.3 = normalized using MinMaxNormalizer(min=0.0,max=10.0) 3.0 = ValueFeature [name=popularity, params={value=3}] 1.600000023841858 = prod of: 0.4 = weight on feature 4.0 = ValueFeature [name=text, params={value=4}] 0.6156155094504356 = prod of: 0.1231231 = weight on feature 5.0 = ValueFeature [name=queryIntentPerson, params={value=5}] 0.6060605496168137 = prod of: 0.12121211 = weight on feature 5.0 = ValueFeature [name=queryIntentCompany, params={value=5}] ' @ debug/explain/7
Stack Trace:
java.lang.RuntimeException: mismatch: '
3.5116758 = LinearModel(name=6029760550880411648,featureWeights=[title=0.0,description=0.1,keywords=0.2,popularity=0.3,text=0.4,queryIntentPerson=0.1231231,queryIntentCompany=0.12121211]) model applied to features, sum of:
0.0 = prod of:
0.0 = weight on feature
1.0 = ValueFeature [name=title, params={value=1}]
0.2 = prod of:
0.1 = weight on feature
2.0 = ValueFeature [name=description, params={value=2}]
0.4 = prod of:
0.2 = weight on feature
2.0 = ValueFeature [name=keywords, params={value=2}]
0.09 = prod of:
0.3 = weight on feature
0.3 = normalized using MinMaxNormalizer(min=0.0,max=10.0)
3.0 = ValueFeature [name=popularity, params={value=3}]
1.6 = prod of:
0.4 = weight on feature
4.0 = ValueFeature [name=text, params={value=4}]
0.6156155 = prod of:
0.1231231 = weight on feature
5.0 = ValueFeature [name=queryIntentPerson, params={value=5}]
0.60606056 = prod of:
0.12121211 = weight on feature
5.0 = ValueFeature [name=queryIntentCompany, params={value=5}]
'!='
3.5116758 = LinearModel(name=6029760550880411648,featureWeights=[title=0.0,description=0.1,keywords=0.2,popularity=0.3,text=0.4,queryIntentPerson=0.1231231,queryIntentCompany=0.12121211]) model applied to features, sum of:
0.0 = prod of:
0.0 = weight on feature
1.0 = ValueFeature [name=title, params={value=1}]
0.20000000298023224 = prod of:
0.1 = weight on feature
2.0 = ValueFeature [name=description, params={value=2}]
0.4000000059604645 = prod of:
0.2 = weight on feature
2.0 = ValueFeature [name=keywords, params={value=2}]
0.09000000715255752 = prod of:
0.3 = weight on feature
0.3 = normalized using MinMaxNormalizer(min=0.0,max=10.0)
3.0 = ValueFeature [name=popularity, params={value=3}]
1.600000023841858 = prod of:
0.4 = weight on feature
4.0 = ValueFeature [name=text, params={value=4}]
0.6156155094504356 = prod of:
0.1231231 = weight on feature
5.0 = ValueFeature [name=queryIntentPerson, params={value=5}]
0.6060605496168137 = prod of:
0.12121211 = weight on feature
5.0 = ValueFeature [name=queryIntentCompany, params={value=5}]
' @ debug/explain/7
at __randomizedtesting.SeedInfo.seed([BF50F24C695B12A1:1B79AC8849EBA0FF]:0)
at org.apache.solr.util.RestTestBase.assertJQ(RestTestBase.java:248)
at org.apache.solr.util.RestTestBase.assertJQ(RestTestBase.java:192)
at org.apache.solr.ltr.TestLTRQParserExplain.testRerankedExplainSameBetweenDifferentDocsWithSameFeatures(TestLTRQParserExplain.java:80)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
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:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
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:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
FAILED: org.apache.solr.cloud.autoscaling.sim.TestExecutePlanAction.testIntegration
Error Message:
Stack Trace:
java.util.ConcurrentModificationException
at __randomizedtesting.SeedInfo.seed([DB943222460F3A98:6BF53C0E63309BBD]:0)
at java.util.ArrayList$Itr.checkForComodification(ArrayList.java:901)
at java.util.ArrayList$Itr.next(ArrayList.java:851)
at org.apache.solr.cloud.autoscaling.sim.SimSolrCloudTestCase.tearDown(SimSolrCloudTestCase.java:141)
at sun.reflect.GeneratedMethodAccessor12.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
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:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
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:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 12169 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestExecutePlanAction
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestExecutePlanAction_DB943222460F3A98-001/init-core-data-001
[junit4] 2> 673723 WARN (SUITE-TestExecutePlanAction-seed#[DB943222460F3A98]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=4 numCloses=4
[junit4] 2> 673723 INFO (SUITE-TestExecutePlanAction-seed#[DB943222460F3A98]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 673726 INFO (SUITE-TestExecutePlanAction-seed#[DB943222460F3A98]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 673726 INFO (SUITE-TestExecutePlanAction-seed#[DB943222460F3A98]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 673745 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 673745 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
[junit4] 2> 673745 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 673745 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
[junit4] 2> 673745 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
[junit4] 2> 673747 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testExecute
[junit4] 2> 673747 DEBUG (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 673748 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 673749 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 673749 DEBUG (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 673749 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220)
[junit4] 2> at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335)
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:154)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 673750 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 673750 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 673750 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 673750 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion -1
[junit4] 2> 673750 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 673750 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 673750 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 673751 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 673772 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 673796 DEBUG (ScheduledTrigger-2534-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 673816 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 673837 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 673860 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 673863 DEBUG (simCloudManagerPool-2533-thread-1) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testExecute
[junit4] 2> 673876 DEBUG (simCloudManagerPool-2533-thread-1) [ ] o.a.s.c.Assign Identify nodes using default
[junit4] 2> 673890 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 673909 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction Collection ready after 1372ms
[junit4] 2> 673913 DEBUG (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.ExecutePlanAction -- processing event: {
[junit4] 2> "id":"1505fce86a798140T33nqmts7exph1isszkrommojw",
[junit4] 2> "source":"mock_trigger_name",
[junit4] 2> "eventTime":1514894924829000000,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1514894924829000000],
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}} with context properties: {operations=[org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@61774019, org.apache.solr.cloud.autoscaling.sim.TestExecutePlanAction$1@287f10fb]}
[junit4] 2> 673913 DEBUG (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=MOVEREPLICA&collection=testExecute&targetNode=127.0.0.1:10000_solr&inPlaceMove=true&replica=core_node1
[junit4] 2> 673915 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 673945 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 673975 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 674006 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 674017 DEBUG (simCloudManagerPool-2533-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- new replica: {"core_node4":{
[junit4] 2> "core":"testExecute_shard1_replica_n3",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testExecute",
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "type":"NRT"}}
[junit4] 2> 674036 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 674066 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 674094 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 674117 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 674138 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 674141 DEBUG (simCloudManagerPool-2533-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testExecute / shard1: {"core_node2":{
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "core":"testExecute_shard1_replica_n2",
[junit4] 2> "leader":"true",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":123450000,
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testExecute"}}
[junit4] 2> 674141 DEBUG (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=OVERSEERSTATUS
[junit4] 2> 674148 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction Collection ready after 6ms
[junit4] 2> 674148 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction -------------_ FINAL STATE --------------
[junit4] 2> 674148 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction * Node values: {
[junit4] 2> "127.0.0.1:10001_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":0,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":1000,
[junit4] 2> "sysprop.java.version":"1.8.0_144",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10001_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10001,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10000_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":2,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":980,
[junit4] 2> "sysprop.java.version":"1.8.0_144",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10000_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10000,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}}
[junit4] 2> 674148 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction * Live nodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 674149 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction * Collection testExecute state: DocCollection(testExecute//clusterstate.json/3)={
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node2":{
[junit4] 2> "core":"testExecute_shard1_replica_n2",
[junit4] 2> "leader":"true",
[junit4] 2> "INDEX.sizeInBytes":123450000,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "core":"testExecute_shard1_replica_n3",
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInBytes":123450000,
[junit4] 2> "type":"NRT"}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 674149 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testExecute
[junit4] 2> 674149 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 674149 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 674149 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 674149 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 674149 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 2
[junit4] 2> 674150 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 1
[junit4] 2> 674150 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 0
[junit4] 2> 674150 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: [testExecute]
[junit4] 2> 674150 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 2
[junit4] 2> 674151 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0
[junit4] 2> 674151 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 2
[junit4] 2> 674151 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * testExecute 2
[junit4] 2> 674152 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - active 2
[junit4] 2> 674152 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 674152 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - CREATE 1
[junit4] 2> 674152 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - DELETESTATUS 2
[junit4] 2> 674152 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - MOVEREPLICA 1
[junit4] 2> 674152 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - OVERSEERSTATUS 1
[junit4] 2> 674152 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - REQUESTSTATUS 2
[junit4] 2> 674152 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 674156 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testIntegration
[junit4] 2> 674156 DEBUG (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 674156 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 674156 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 674156 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 674157 DEBUG (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 674157 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 674157 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220)
[junit4] 2> at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335)
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:154)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 674158 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 674158 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 674158 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 674158 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion -1
[junit4] 2> 674158 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 674158 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 674158 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 674159 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 674189 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 674219 DEBUG (ScheduledTrigger-2537-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 674246 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 674268 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 674288 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 674309 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 674330 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 674335 DEBUG (simCloudManagerPool-2536-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 674335 DEBUG (simCloudManagerPool-2536-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 674336 DEBUG (simCloudManagerPool-2536-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 674336 DEBUG (simCloudManagerPool-2536-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 674336 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 674336 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 674336 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 674336 DEBUG (simCloudManagerPool-2536-thread-2) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testIntegration
[junit4] 2> 674336 DEBUG (ScheduledTrigger-2537-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 674350 DEBUG (ScheduledTrigger-2537-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 674350 DEBUG (simCloudManagerPool-2536-thread-2) [ ] o.a.s.c.Assign Identify nodes using default
[junit4] 2> 674360 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 674372 DEBUG (ScheduledTrigger-2537-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 674382 DEBUG (ScheduledTrigger-2537-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 674384 DEBUG (simCloudManagerPool-2536-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testIntegration / shard1: {"core_node1":{
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "core":"testIntegration_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":123450000,
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testIntegration"}}
[junit4] 2> 674392 DEBUG (ScheduledTrigger-2537-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 674392 DEBUG (ScheduledTrigger-2537-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10000_solr
[junit4] 2> 674403 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 1
[junit4] 2> 674403 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10000_solr
[junit4] 2> 674413 DEBUG (ScheduledTrigger-2537-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 674428 DEBUG (ScheduledTrigger-2537-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 1
[junit4] 2> 674428 DEBUG (ScheduledTrigger-2537-thread-4) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10000_solr]
[junit4] 2> 674429 DEBUG (ScheduledTrigger-2537-thread-4) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"13f7ce395121f4T33nqmts7exph1isszkrommojx",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":5620489654444532,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5620489654444532],
[junit4] 2> "nodeNames":["127.0.0.1:10000_solr"]}}
[junit4] 2> 674429 DEBUG (AutoscalingActionExecutor-2538-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"13f7ce395121f4T33nqmts7exph1isszkrommojx",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":5620489654444532,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5620489654444532],
[junit4] 2> "_enqueue_time_":5620490924258232,
[junit4] 2> "nodeNames":["127.0.0.1:10000_solr"]}}
[junit4] 2> 674429 DEBUG (AutoscalingActionExecutor-2538-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"13f7ce395121f4T33nqmts7exph1isszkrommojx",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":5620489654444532,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5620489654444532],
[junit4] 2> "_enqueue_time_":5620490924258232,
[junit4] 2> "nodeNames":["127.0.0.1:10000_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 674431 INFO (AutoscalingActionExecutor-2538-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testIntegration&targetNode=127.0.0.1:10001_solr&inPlaceMove=true&replica=core_node2
[junit4] 2> 674432 INFO (AutoscalingActionExecutor-2538-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 5620491088 sessionWrapper.createTime 5620491008758182, this.sessionWrapper.createTime 5620491008758182
[junit4] 2> 674432 DEBUG (AutoscalingActionExecutor-2538-thread-1) [ ] o.a.s.c.a.ExecutePlanAction -- processing event: {
[junit4] 2> "id":"13f7ce395121f4T33nqmts7exph1isszkrommojx",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":5620489654444532,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5620489654444532],
[junit4] 2> "_enqueue_time_":5620490924258232,
[junit4] 2> "nodeNames":["127.0.0.1:10000_solr"]}} with context properties: {operations=[org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@1c4d6e44], AFTER_ACTION=[compute_plan], BEFORE_ACTION=[compute_plan, execute_plan]}
[junit4] 2> 674432 DEBUG (AutoscalingActionExecutor-2538-thread-1) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=MOVEREPLICA&collection=testIntegration&targetNode=127.0.0.1:10001_solr&inPlaceMove=true&replica=core_node2
[junit4] 2> 674533 DEBUG (simCloudManagerPool-2536-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- new replica: {"core_node4":{
[junit4] 2> "core":"testIntegration_shard1_replica_n3",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testIntegration",
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "type":"NRT"}}
[junit4] 2> 674650 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction -------------_ FINAL STATE --------------
[junit4] 2> 674650 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction * Node values: {
[junit4] 2> "127.0.0.1:10001_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":2,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":980,
[junit4] 2> "sysprop.java.version":"1.8.0_144",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10001_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10001,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10000_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":970,
[junit4] 2> "sysprop.java.version":"1.8.0_144",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10000_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10000,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}}
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction * Live nodes: [127.0.0.1:10001_solr]
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction * Collection testIntegration state: DocCollection(testIntegration//clusterstate.json/10)={
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":"testIntegration_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "INDEX.sizeInBytes":123450000,
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "core":"testIntegration_shard1_replica_n3",
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInBytes":123450000,
[junit4] 2> "type":"NRT"}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testIntegration
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 1
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 0
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 1
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## 127.0.0.1:10000_solr
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: [testIntegration]
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 2
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 2
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 2
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * testIntegration 2
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - active 2
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - CREATE 1
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - DELETESTATUS 1
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - MOVEREPLICA 1
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - REQUESTSTATUS 1
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 1
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 1
[junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 674651 DEBUG (AutoscalingActionExecutor-2538-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 11101 ms for event id=13f7ce395121f4T33nqmts7exph1isszkrommojx
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestExecutePlanAction -Dtests.method=testIntegration -Dtests.seed=DB943222460F3A98 -Dtests.slow=true -Dtests.locale=sv -Dtests.timezone=Africa/Porto-Novo -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.50s J0 | TestExecutePlanAction.testIntegration <<<
[junit4] > Throwable #1: java.util.ConcurrentModificationException
[junit4] > at __randomizedtesting.SeedInfo.seed([DB943222460F3A98:6BF53C0E63309BBD]:0)
[junit4] > at java.util.ArrayList$Itr.checkForComodification(ArrayList.java:901)
[junit4] > at java.util.ArrayList$Itr.next(ArrayList.java:851)
[junit4] > at org.apache.solr.cloud.autoscaling.sim.SimSolrCloudTestCase.tearDown(SimSolrCloudTestCase.java:141)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 674654 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 674654 DEBUG (SUITE-TestExecutePlanAction-seed#[DB943222460F3A98]-worker) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestExecutePlanAction_DB943222460F3A98-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=839, maxMBSortInHeap=5.924442087858636, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@6fef801c), locale=sv, timezone=Africa/Porto-Novo
[junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=3,threads=1,free=218802608,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [ResponseLogComponentTest, SpellCheckCollatorTest, TestSolrConfigHandlerConcurrent, CursorPagingTest, EnumFieldTest, TestBinaryField, TestComplexPhraseQParserPlugin, AtomicUpdateProcessorFactoryTest, MultiTermTest, NotRequiredUniqueKeyTest, TestIBSimilarityFactory, TestSweetSpotSimilarityFactory, TestMaxScoreQueryParser, BlobRepositoryCloudTest, TestCopyFieldCollectionResource, TestDynamicFieldResource, DirectUpdateHandlerTest, TestManagedResource, TestOrdValues, TestAuthenticationFramework, CdcrVersionReplicationTest, BigEndianAscendingWordSerializerTest, SolrCloudExampleTest, UnloadDistributedZkTest, TestCoreBackup, RegexBytesRefFilterTest, SuggesterTest, InfixSuggestersTest, TestDFRSimilarityFactory, TestDistribIDF, TestUseDocValuesAsStored, HdfsWriteToMultipleCollectionsTest, TestRandomCollapseQParserPlugin, TestXIncludeConfig, TestFieldCacheVsDocValues, RequiredFieldsTest, SpatialRPTFieldTypeTest, TestSolrCoreProperties, PeerSyncWithIndexFingerprintCachingTest, TestFieldCacheSort, TestFiltering, TestRawResponseWriter, DistanceUnitsTest, SSLMigrationTest, TestRestoreCore, TestCloudInspectUtil, TestCursorMarkWithoutUniqueKey, TestRandomDVFaceting, BJQParserTest, TestFieldTypeResource, DeleteInactiveReplicaTest, TestLFUCache, TestLockTree, TestStressLiveNodes, MissingSegmentRecoveryTest, TestQuerySenderListener, SegmentsInfoRequestHandlerTest, SyncSliceTest, CircularListTest, TestHdfsUpdateLog, HdfsTlogReplayBufferedWhileIndexingTest, CreateCollectionCleanupTest, TestDistributedStatsComponentCardinality, TestStressCloudBlindAtomicUpdates, TestTolerantUpdateProcessorCloud, TestXmlQParser, TestSchemaVersionResource, TestLegacyField, DocExpirationUpdateProcessorFactoryTest, TestLMDirichletSimilarityFactory, TestInPlaceUpdatesStandalone, TestScoreJoinQPScore, TestFreeTextSuggestions, BasicAuthIntegrationTest, TestSurroundQueryParser, TestMultiWordSynonyms, LegacyCloudClusterPropTest, TestSha256AuthenticationProvider, TestZkAclsWithHadoopAuth, DistributedFacetPivotLongTailTest, TestHttpShardHandlerFactory, TestCustomDocTransformer, ChaosMonkeyNothingIsSafeTest, TestReloadDeadlock, CoreSorterTest, ZkStateWriterTest, TestNonDefinedSimilarityFactory, LeaderFailoverAfterPartitionTest, DistributedDebugComponentTest, TestExecutePlanAction]
[junit4] Completed [164/765 (1!)] on J0 in 0.94s, 2 tests, 1 error <<< FAILURES!
[...truncated 9343 lines...]
[junit4] Suite: org.apache.solr.ltr.TestLTRQParserExplain
[junit4] 2> 49795 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/init-core-data-001
[junit4] 2> 49797 WARN (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=24 numCloses=24
[junit4] 2> 49797 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 49801 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 49802 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore
[junit4] 2> 49818 WARN (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.c.SolrConfig Couldn't add files from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/contrib/ltr/src/test-files/solr/models filtered by null to classpath: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/contrib/ltr/src/test-files/solr/models
[junit4] 2> 49827 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 49838 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.s.IndexSchema [null] Schema name=example
[junit4] 2> 49849 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.s.IndexSchema Loaded schema example/1.5 with uniqueid field id
[junit4] 2> 49941 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e063592
[junit4] 2> 49961 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e063592
[junit4] 2> 49962 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e063592
[junit4] 2> 49964 INFO (coreLoadExecutor-329-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 49979 WARN (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.c.SolrConfig Couldn't add files from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/contrib/ltr/src/test-files/solr/models filtered by null to classpath: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/contrib/ltr/src/test-files/solr/models
[junit4] 2> 49981 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 49991 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=example
[junit4] 2> 50016 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema example/1.5 with uniqueid field id
[junit4] 2> 50019 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/contrib/ltr/src/test-files/solr/collection1, trusted=true
[junit4] 2> 50019 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e063592
[junit4] 2> 50019 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 50019 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/contrib/ltr/src/test-files/solr/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/init-core-data-001/]
[junit4] 2> 50131 WARN (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.c.RequestHandlers no default request handler is registered (either '/select' or 'standard')
[junit4] 2> 50132 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 50132 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 50163 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms;
[junit4] 2> 50163 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: if uncommited for 1000ms;
[junit4] 2> 50167 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@436f5833[collection1] main]
[junit4] 2> 50167 WARN (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage Cannot write to config directory /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/contrib/ltr/src/test-files/solr/collection1/conf; switching to use InMemory storage instead.
[junit4] 2> 50167 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.r.RestManager Registered ManagedResource impl org.apache.solr.ltr.store.rest.ManagedFeatureStore for path /schema/feature-store
[junit4] 2> 50167 WARN (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.r.ManagedResource No stored data found for /schema/feature-store
[junit4] 2> 50167 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore ------ managed feature ~ loading ------
[junit4] 2> 50167 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.r.ManagedResource Notified 1 observers of /schema/feature-store
[junit4] 2> 50167 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.r.RestManager Registered new managed resource /schema/feature-store
[junit4] 2> 50167 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.r.RestManager Registered ManagedResource impl org.apache.solr.ltr.store.rest.ManagedModelStore for path /schema/model-store
[junit4] 2> 50168 WARN (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.r.ManagedResource No stored data found for /schema/model-store
[junit4] 2> 50168 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.l.s.r.ManagedModelStore INIT model store
[junit4] 2> 50168 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.l.s.r.ManagedModelStore ------ managed models ~ loading ------
[junit4] 2> 50168 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.r.ManagedResource Notified 1 observers of /schema/model-store
[junit4] 2> 50168 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.r.RestManager Registered new managed resource /schema/model-store
[junit4] 2> 50168 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 50170 INFO (searcherExecutor-330-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@436f5833[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 50171 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1588486125193789440
[junit4] 2> 50176 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end
[junit4] 2> 50186 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore
[junit4] 2> 50186 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end
[junit4] 2> 50187 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-003/cores/core
[junit4] 2> 50189 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 50191 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3399363e{/solr,null,AVAILABLE}
[junit4] 2> 50192 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3795cdb7{HTTP/1.1,[http/1.1]}{127.0.0.1:53047}
[junit4] 2> 50192 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.e.j.s.Server Started @53029ms
[junit4] 2> 50192 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=53047, configSetBaseDir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-001, coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-003/cores}
[junit4] 2> 50193 ERROR (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 50193 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
[junit4] 2> 50193 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 50193 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 50194 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-02T13:06:59.587Z
[junit4] 2> 50194 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-001/solr.xml
[junit4] 2> 50301 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@6e063592, but no JMX reporters were configured - adding default JMX reporter.
[junit4] 2> 50472 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e063592
[junit4] 2> 50503 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e063592
[junit4] 2> 50517 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e063592
[junit4] 2> 50524 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-003/cores
[junit4] 2> 50524 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 50528 INFO (coreLoadExecutor-340-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 50577 WARN (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.c.SolrConfig Couldn't add files from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-001/models filtered by null to classpath: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-001/models
[junit4] 2> 50580 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 50658 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=example
[junit4] 2> 50669 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema example/1.5 with uniqueid field id
[junit4] 2> 50683 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from configset /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-001/collection1, trusted=true
[junit4] 2> 50693 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e063592
[junit4] 2> 50693 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 50693 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-001/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-003/cores/core/data/]
[junit4] 2> 50886 WARN (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.c.RequestHandlers no default request handler is registered (either '/select' or 'standard')
[junit4] 2> 50887 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 50887 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 50890 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms;
[junit4] 2> 50890 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: if uncommited for 1000ms;
[junit4] 2> 50929 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4b836e02[collection1] main]
[junit4] 2> 50930 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-001/collection1/conf
[junit4] 2> 50931 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.r.RestManager Registered ManagedResource impl org.apache.solr.ltr.store.rest.ManagedFeatureStore for path /schema/feature-store
[junit4] 2> 50931 WARN (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.r.ManagedResource No stored data found for /schema/feature-store
[junit4] 2> 50931 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore ------ managed feature ~ loading ------
[junit4] 2> 50931 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.r.ManagedResource Notified 1 observers of /schema/feature-store
[junit4] 2> 50931 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.r.RestManager Registered new managed resource /schema/feature-store
[junit4] 2> 50931 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.r.RestManager Registered ManagedResource impl org.apache.solr.ltr.store.rest.ManagedModelStore for path /schema/model-store
[junit4] 2> 50932 WARN (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.r.ManagedResource No stored data found for /schema/model-store
[junit4] 2> 50932 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.l.s.r.ManagedModelStore INIT model store
[junit4] 2> 50932 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.l.s.r.ManagedModelStore ------ managed models ~ loading ------
[junit4] 2> 50932 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.r.ManagedResource Notified 1 observers of /schema/model-store
[junit4] 2> 50932 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.r.RestManager Registered new managed resource /schema/model-store
[junit4] 2> 50933 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 50933 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1588486125992804352
[junit4] 2> 50936 INFO (searcherExecutor-341-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@4b836e02[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 50937 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrJettyTestBase Jetty Assigned Port#53047
[junit4] 2> 50961 INFO (qtp511526317-485) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={stream.body=<add><doc><field+name%3D"title">bloomberg+different+bla</field><field+name%3D"description">bloomberg</field><field+name%3D"id">6</field><field+name%3D"popularity">1</field></doc></add>}{add=[6 (1588486126007484416)]} 0 15
[junit4] 2> 50971 INFO (qtp511526317-486) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={stream.body=<add><doc><field+name%3D"title">bloomberg+bloomberg+</field><field+name%3D"description">bloomberg</field><field+name%3D"id">7</field><field+name%3D"popularity">2</field></doc></add>}{add=[7 (1588486126030553088)]} 0 3
[junit4] 2> 50975 INFO (qtp511526317-487) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={stream.body=<add><doc><field+name%3D"title">bloomberg+bloomberg+bloomberg</field><field+name%3D"description">bloomberg</field><field+name%3D"id">8</field><field+name%3D"popularity">3</field></doc></add>}{add=[8 (1588486126035795968)]} 0 1
[junit4] 2> 50982 INFO (qtp511526317-488) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={stream.body=<add><doc><field+name%3D"title">bloomberg+bloomberg+bloomberg+bloomberg</field><field+name%3D"description">bloomberg</field><field+name%3D"id">9</field><field+name%3D"popularity">5</field></doc></add>}{add=[9 (1588486126043136000)]} 0 1
[junit4] 2> 50985 INFO (qtp511526317-489) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1588486126047330304,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 50985 INFO (qtp511526317-489) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@212b3cf commitCommandVersion:1588486126047330304
[junit4] 2> 51172 INFO (qtp511526317-489) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@598abb28[collection1] main]
[junit4] 2> 51173 INFO (qtp511526317-489) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 51176 INFO (searcherExecutor-341-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@598abb28[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C4)))}
[junit4] 2> 51177 INFO (qtp511526317-489) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={stream.body=<commit/>}{commit=} 0 192
[junit4] 2> 51185 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.l.TestRerankBase send
[junit4] 2> [
[junit4] 2> {
[junit4] 2> "name": "constant1",
[junit4] 2> "class": "org.apache.solr.ltr.feature.ValueFeature",
[junit4] 2> "store":"test",
[junit4] 2> "params": {
[junit4] 2> "value": 1
[junit4] 2> }
[junit4] 2> },
[junit4] 2> {
[junit4] 2> "name": "constant2",
[junit4] 2> "class": "org.apache.solr.ltr.feature.ValueFeature",
[junit4] 2> "store":"test",
[junit4] 2> "params": {
[junit4] 2> "value": 2
[junit4] 2> }
[junit4] 2> },
[junit4] 2> {
[junit4] 2> "name": "constant3",
[junit4] 2> "class": "org.apache.solr.ltr.feature.ValueFeature",
[junit4] 2> "store":"test",
[junit4] 2> "params": {
[junit4] 2> "value": 3
[junit4] 2> }
[junit4] 2> },
[junit4] 2> {
[junit4] 2> "name": "constant4",
[junit4] 2> "class": "org.apache.solr.ltr.feature.ValueFeature",
[junit4] 2> "store":"test",
[junit4] 2> "params": {
[junit4] 2> "value": 4
[junit4] 2> }
[junit4] 2> },
[junit4] 2> {
[junit4] 2> "name": "constant5",
[junit4] 2> "class": "org.apache.solr.ltr.feature.ValueFeature",
[junit4] 2> "store":"test",
[junit4] 2> "params": {
[junit4] 2> "value": 5
[junit4] 2> }
[junit4] 2> },
[junit4] 2> {
[junit4] 2> "name": "pop",
[junit4] 2> "class": "org.apache.solr.ltr.feature.FieldValueFeature",
[junit4] 2> "store":"test",
[junit4] 2> "params": {
[junit4] 2> "field": "popularity"
[junit4] 2> }
[junit4] 2> }
[junit4] 2>
[junit4] 2> ]
[junit4] 2>
[junit4] 2> 51187 INFO (qtp511526317-490) [ x:collection1] /solr SolrSchemaRestApi: [Restlet] ServerServlet: component class is null
[junit4] 2> 51188 INFO (qtp511526317-490) [ x:collection1] /solr SolrSchemaRestApi: [Restlet] Attaching application: org.apache.solr.rest.SolrSchemaRestApi@a5c75eb to URI: /solr/schema
[junit4] 2> Jan 02, 2018 8:07:00 AM org.restlet.Application start
[junit4] 2> INFO: Starting org.apache.solr.rest.SolrSchemaRestApi application
[junit4] 2> 51211 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.SolrSchemaRestApi createInboundRoot started for /schema
[junit4] 2> 51211 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.RestManager Attached managed resource at path: /feature-store
[junit4] 2> 51211 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.RestManager Attached managed resource at path: /managed
[junit4] 2> 51212 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.RestManager Attached managed resource at path: /model-store
[junit4] 2> 51212 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.RestManager Attached 3 ManagedResource endpoints to Restlet router: /schema
[junit4] 2> 51212 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.SolrSchemaRestApi createInboundRoot complete for /schema
[junit4] 2> 51212 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.RestManager Found ManagedResource [org.apache.solr.ltr.store.rest.ManagedFeatureStore@3ad3c526] for /schema/feature-store
[junit4] 2> 51213 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.ManagedResource Processing update to /schema/feature-store: [{name=constant1, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=1}}, {name=constant2, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=2}}, {name=constant3, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=3}}, {name=constant4, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=4}}, {name=constant5, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=5}}, {name=pop, class=org.apache.solr.ltr.feature.FieldValueFeature, store=test, params={field=popularity}}] is a java.util.ArrayList
[junit4] 2> 51213 INFO (qtp511526317-490) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore register feature based on {name=constant1, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=1}}
[junit4] 2> 51253 INFO (qtp511526317-490) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore register feature based on {name=constant2, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=2}}
[junit4] 2> 51253 INFO (qtp511526317-490) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore register feature based on {name=constant3, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=3}}
[junit4] 2> 51253 INFO (qtp511526317-490) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore register feature based on {name=constant4, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=4}}
[junit4] 2> 51254 INFO (qtp511526317-490) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore register feature based on {name=constant5, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=5}}
[junit4] 2> 51254 INFO (qtp511526317-490) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore register feature based on {name=pop, class=org.apache.solr.ltr.feature.FieldValueFeature, store=test, params={field=popularity}}
[junit4] 2> 51267 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.ManagedResourceStorage Saved JSON object to path _schema_feature-store.json using file:dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-001/collection1/conf
[junit4] 2> 51268 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.RestManager [collection1] webapp=/solr path=/schema/feature-store params={indent=on&wt=json} status=0 QTime=81
[junit4] 2> Jan 02, 2018 8:07:00 AM org.restlet.engine.log.LogFilter afterHandle
[junit4] 2> INFO: 2018-01-02 08:07:00 127.0.0.1 - 127.0.0.1 53047 PUT /solr/schema/feature-store wt=json&indent=on 200 - 1077 79 http://127.0.0.1:53047 Apache-HttpClient/4.5.3 (Java/1.8.0_144) -
[junit4] 2> 51269 WARN (qtp511526317-490) [ x:collection1] o.e.j.s.ServletHandler Error for /solr/collection1/schema/feature-store
[junit4] 2> java.lang.AssertionError: Attempted close of response output stream.
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter$2$1.close(SolrDispatchFilter.java:525)
[junit4] 2> at org.eclipse.jetty.server.Dispatcher.commitResponse(Dispatcher.java:270)
[junit4] 2> at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:202)
[junit4] 2> at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:74)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:391)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:326)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:426)
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
[junit4] 2> at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 51278 INFO (TEST-TestLTRQParserExplain.multipleAdditiveTreesScoreExplainMissingEfiFeatureShouldReturnDefaultScore-seed#[BF50F24C695B12A1]) [ ] o.a.s.SolrTestCaseJ4 ###Starting multipleAdditiveTreesScoreExplainMissingEfiFeatureShouldReturnDefaultScore
[junit4] 2> 51279 INFO (TEST-TestLTRQParserExplain.multipleAdditiveTreesScoreExplainMissingEfiFeatureShouldReturnDefaultScore-seed#[BF50F24C695B12A1]) [ ] o.a.s.l.TestRerankBase send
[junit4] 2> [{
[junit4] 2> "name" : "user_device_smartphone",
[junit4] 2> "class":"org.apache.solr.ltr.feature.ValueFeature",
[junit4] 2> "params" : {
[junit4] 2> "value": "${user_device_smartphone}"
[junit4] 2> }
[junit4] 2> },
[junit4] 2> {
[junit4] 2> "name" : "user_device_tablet",
[junit4] 2> "class":"org.apache.solr.ltr.feature.ValueFeature",
[junit4] 2> "params" : {
[junit4] 2> "value": "${user_device_tablet}"
[junit4] 2> }
[junit4] 2> }
[junit4] 2>
[junit4] 2>
[junit4] 2>
[junit4] 2> ]
[junit4] 2>
[junit4] 2> 51282 INFO (qtp511526317-483) [ x:collection1] o.a.s.r.RestManager Found ManagedResource [org.apache.solr.ltr.store.rest.ManagedFeatureStore@3ad3c526] for /schema/feature-store
[junit4] 2> 51282 INFO (qtp511526317-483) [ x:collection1] o.a.s.r.ManagedResource Processing update to /schema/feature-store: [{name=user_device_smartphone, class=org.apache.solr.ltr.feature.ValueFeature, params={value=${user_device_smartphone}}}, {name=user_device_tablet, class=org.apache.solr.ltr.feature.ValueFeature, params={value=${user_device_tablet}}}] is a java.util.ArrayList
[junit4] 2> 51282 INFO (qtp511526317-483) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore register feature based on {name=user_device_smartphone, class=org.apache.solr.ltr.feature.ValueFeature, params={value=${user_device_smartphone}}}
[junit4] 2> 51282 INFO (qtp511526317-483) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore register feature based on {name=user_device_tablet, class=org.apache.solr.ltr.feature.ValueFeature, params={value=${user_device_tablet}}}
[junit4] 2> 51283 INFO (qtp511526317-483) [ x:collection1] o.a.s.r.ManagedResourceStorage Saved JSON object to path _schema_feature-store.json using file:dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-001/collection1/conf
[junit4] 2> 51283 INFO (qtp511526317-483) [ x:collection1] o.a.s.r.RestManager [collection1] webapp=/solr path=/schema/feature-store params={indent=on&wt=json} status=0 QTime=3
[junit4] 2> Jan 02, 2018 8:07:00 AM org.restlet.engine.log.LogFilter afterHandle
[junit4] 2> INFO: 2018-01-02 08:07:00 127.0.0.1 - 127.0.0.1 53047 PUT /solr/schema/feature-store wt=json&indent=on 200 - 323 2 http://127.0.0.1:53047 Apache-HttpClient/4.5.3 (Java/1.8.0_144) -
[junit4] 2> 51284 WARN (qtp511526317-483) [ x:collection1] o.e.j.s.ServletHandler Error for /solr/collection1/schema/feature-store
[junit4] 2> java.lang.AssertionError: Attempted close of response output stream.
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter$2$1.close(SolrDispatchFilter.java:525)
[junit4] 2> at org.eclipse.jetty.server.Dispatcher.commitResponse(Dispatcher.java:270)
[junit4] 2> at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:202)
[junit4] 2> at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:74)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:391)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:326)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:426)
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.
[...truncated too long message...]
mitResponse(Dispatcher.java:270)
[junit4] 2> at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:202)
[junit4] 2> at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:74)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:391)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:326)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:426)
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
[junit4] 2> at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 51497 INFO (qtp511526317-488) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/query params={q=title:bloomberg&indent=on&fl=*,score&rows=4&wt=json&debugQuery=on&rq={!ltr+reRankDocs%3D4+model%3Dlinear-efi}} hits=4 status=0 QTime=2
[junit4] 2> 51501 INFO (qtp511526317-489) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/query params={q=title:bloomberg&indent=on&fl=*,score&rows=4&wt=json&debugQuery=on&rq={!ltr+reRankDocs%3D4+model%3Dlinear-efi}} hits=4 status=0 QTime=2
[junit4] 2> 51502 INFO (TEST-TestLTRQParserExplain.LinearScoreExplainMissingEfiFeatureShouldReturnDefaultScore-seed#[BF50F24C695B12A1]) [ ] o.a.s.SolrTestCaseJ4 ###Ending LinearScoreExplainMissingEfiFeatureShouldReturnDefaultScore
[junit4] 2> 51504 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@3795cdb7{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 51504 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=322867989
[junit4] 2> 51504 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 51504 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3cb2da54: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@1f9092bf
[junit4] 2> 51514 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 51514 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@14ecc590: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@6e6a01b9
[junit4] 2> 51521 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 51521 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4a6f3ed6: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@6a5598ac
[junit4] 2> 51523 INFO (coreCloseExecutor-346-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@31fc24c5
[junit4] 2> 51523 INFO (coreCloseExecutor-346-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=838608069
[junit4] 2> 51523 INFO (coreCloseExecutor-346-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@573053f4: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@7fcb7594
[junit4] 2> 51551 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@3399363e{/solr,null,UNAVAILABLE}
[junit4] 2> 51573 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> 51573 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1918236122
[junit4] 2> 51573 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 51573 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4ab04e5b: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@6987c674
[junit4] 2> 51574 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 51574 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@720828e1: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@6e6a01b9
[junit4] 2> 51575 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 51575 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1871c8a5: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@6a5598ac
[junit4] 2> 51576 INFO (coreCloseExecutor-348-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@46946a09
[junit4] 2> 51576 INFO (coreCloseExecutor-348-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=1184131593
[junit4] 2> 51576 INFO (coreCloseExecutor-348-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3717fa34: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@495237ee
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001
[junit4] 2> NOTE: test params are: codec=Lucene70, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@6b4359a7), locale=en-GB, timezone=America/Montreal
[junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=3,threads=1,free=106751488,total=198180864
[junit4] 2> NOTE: All tests run in this JVM: [TestModelManagerPersistence, TestRerankBase, TestMultipleAdditiveTreesModel, TestOriginalScoreScorer, TestFeatureLogging, TestExternalValueFeatures, TestUserTermScoreWithQ, TestFieldValueFeature, TestEdisMaxSolrFeature, TestLTROnSolrCloud, TestLTRQParserExplain]
[junit4] Completed [20/35 (1!)] on J0 in 1.83s, 4 tests, 1 error <<< FAILURES!
[...truncated 40705 lines...]
Re: [JENKINS] Lucene-Solr-master-MacOSX (64bit/jdk1.8.0) - Build #
4360 - Unstable!
Posted by Alan Woodward <ro...@gmail.com>.
This is LUCENE-8012 I think, digging now.
> On 2 Jan 2018, at 13:20, Policeman Jenkins Server <je...@thetaphi.de> wrote:
>
> Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/4360/
> Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseG1GC
>
> 2 tests failed.
> FAILED: org.apache.solr.ltr.TestLTRQParserExplain.testRerankedExplainSameBetweenDifferentDocsWithSameFeatures
>
> Error Message:
> mismatch: ' 3.5116758 = LinearModel(name=6029760550880411648,featureWeights=[title=0.0,description=0.1,keywords=0.2,popularity=0.3,text=0.4,queryIntentPerson=0.1231231,queryIntentCompany=0.12121211]) model applied to features, sum of: 0.0 = prod of: 0.0 = weight on feature 1.0 = ValueFeature [name=title, params={value=1}] 0.2 = prod of: 0.1 = weight on feature 2.0 = ValueFeature [name=description, params={value=2}] 0.4 = prod of: 0.2 = weight on feature 2.0 = ValueFeature [name=keywords, params={value=2}] 0.09 = prod of: 0.3 = weight on feature 0.3 = normalized using MinMaxNormalizer(min=0.0,max=10.0) 3.0 = ValueFeature [name=popularity, params={value=3}] 1.6 = prod of: 0.4 = weight on feature 4.0 = ValueFeature [name=text, params={value=4}] 0.6156155 = prod of: 0.1231231 = weight on feature 5.0 = ValueFeature [name=queryIntentPerson, params={value=5}] 0.60606056 = prod of: 0.12121211 = weight on feature 5.0 = ValueFeature [name=queryIntentCompany, params={value=5}] '!=' 3.5116758 = LinearModel(name=6029760550880411648,featureWeights=[title=0.0,description=0.1,keywords=0.2,popularity=0.3,text=0.4,queryIntentPerson=0.1231231,queryIntentCompany=0.12121211]) model applied to features, sum of: 0.0 = prod of: 0.0 = weight on feature 1.0 = ValueFeature [name=title, params={value=1}] 0.20000000298023224 = prod of: 0.1 = weight on feature 2.0 = ValueFeature [name=description, params={value=2}] 0.4000000059604645 = prod of: 0.2 = weight on feature 2.0 = ValueFeature [name=keywords, params={value=2}] 0.09000000715255752 = prod of: 0.3 = weight on feature 0.3 = normalized using MinMaxNormalizer(min=0.0,max=10.0) 3.0 = ValueFeature [name=popularity, params={value=3}] 1.600000023841858 = prod of: 0.4 = weight on feature 4.0 = ValueFeature [name=text, params={value=4}] 0.6156155094504356 = prod of: 0.1231231 = weight on feature 5.0 = ValueFeature [name=queryIntentPerson, params={value=5}] 0.6060605496168137 = prod of: 0.12121211 = weight on feature 5.0 = ValueFeature [name=queryIntentCompany, params={value=5}] ' @ debug/explain/7
>
> Stack Trace:
> java.lang.RuntimeException: mismatch: '
> 3.5116758 = LinearModel(name=6029760550880411648,featureWeights=[title=0.0,description=0.1,keywords=0.2,popularity=0.3,text=0.4,queryIntentPerson=0.1231231,queryIntentCompany=0.12121211]) model applied to features, sum of:
> 0.0 = prod of:
> 0.0 = weight on feature
> 1.0 = ValueFeature [name=title, params={value=1}]
> 0.2 = prod of:
> 0.1 = weight on feature
> 2.0 = ValueFeature [name=description, params={value=2}]
> 0.4 = prod of:
> 0.2 = weight on feature
> 2.0 = ValueFeature [name=keywords, params={value=2}]
> 0.09 = prod of:
> 0.3 = weight on feature
> 0.3 = normalized using MinMaxNormalizer(min=0.0,max=10.0)
> 3.0 = ValueFeature [name=popularity, params={value=3}]
> 1.6 = prod of:
> 0.4 = weight on feature
> 4.0 = ValueFeature [name=text, params={value=4}]
> 0.6156155 = prod of:
> 0.1231231 = weight on feature
> 5.0 = ValueFeature [name=queryIntentPerson, params={value=5}]
> 0.60606056 = prod of:
> 0.12121211 = weight on feature
> 5.0 = ValueFeature [name=queryIntentCompany, params={value=5}]
> '!='
> 3.5116758 = LinearModel(name=6029760550880411648,featureWeights=[title=0.0,description=0.1,keywords=0.2,popularity=0.3,text=0.4,queryIntentPerson=0.1231231,queryIntentCompany=0.12121211]) model applied to features, sum of:
> 0.0 = prod of:
> 0.0 = weight on feature
> 1.0 = ValueFeature [name=title, params={value=1}]
> 0.20000000298023224 = prod of:
> 0.1 = weight on feature
> 2.0 = ValueFeature [name=description, params={value=2}]
> 0.4000000059604645 = prod of:
> 0.2 = weight on feature
> 2.0 = ValueFeature [name=keywords, params={value=2}]
> 0.09000000715255752 = prod of:
> 0.3 = weight on feature
> 0.3 = normalized using MinMaxNormalizer(min=0.0,max=10.0)
> 3.0 = ValueFeature [name=popularity, params={value=3}]
> 1.600000023841858 = prod of:
> 0.4 = weight on feature
> 4.0 = ValueFeature [name=text, params={value=4}]
> 0.6156155094504356 = prod of:
> 0.1231231 = weight on feature
> 5.0 = ValueFeature [name=queryIntentPerson, params={value=5}]
> 0.6060605496168137 = prod of:
> 0.12121211 = weight on feature
> 5.0 = ValueFeature [name=queryIntentCompany, params={value=5}]
> ' @ debug/explain/7
> at __randomizedtesting.SeedInfo.seed([BF50F24C695B12A1:1B79AC8849EBA0FF]:0)
> at org.apache.solr.util.RestTestBase.assertJQ(RestTestBase.java:248)
> at org.apache.solr.util.RestTestBase.assertJQ(RestTestBase.java:192)
> at org.apache.solr.ltr.TestLTRQParserExplain.testRerankedExplainSameBetweenDifferentDocsWithSameFeatures(TestLTRQParserExplain.java:80)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
> 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:45)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
> 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:53)
> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
> at java.lang.Thread.run(Thread.java:748)
>
>
> FAILED: org.apache.solr.cloud.autoscaling.sim.TestExecutePlanAction.testIntegration
>
> Error Message:
>
>
> Stack Trace:
> java.util.ConcurrentModificationException
> at __randomizedtesting.SeedInfo.seed([DB943222460F3A98:6BF53C0E63309BBD]:0)
> at java.util.ArrayList$Itr.checkForComodification(ArrayList.java:901)
> at java.util.ArrayList$Itr.next(ArrayList.java:851)
> at org.apache.solr.cloud.autoscaling.sim.SimSolrCloudTestCase.tearDown(SimSolrCloudTestCase.java:141)
> at sun.reflect.GeneratedMethodAccessor12.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
> 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:45)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
> 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:53)
> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
> at java.lang.Thread.run(Thread.java:748)
>
>
>
>
> Build Log:
> [...truncated 12169 lines...]
> [junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestExecutePlanAction
> [junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestExecutePlanAction_DB943222460F3A98-001/init-core-data-001
> [junit4] 2> 673723 WARN (SUITE-TestExecutePlanAction-seed#[DB943222460F3A98]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=4 numCloses=4
> [junit4] 2> 673723 INFO (SUITE-TestExecutePlanAction-seed#[DB943222460F3A98]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
> [junit4] 2> 673726 INFO (SUITE-TestExecutePlanAction-seed#[DB943222460F3A98]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) w/ MAC_OS_X supressed clientAuth
> [junit4] 2> 673726 INFO (SUITE-TestExecutePlanAction-seed#[DB943222460F3A98]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
> [junit4] 2> 673745 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
> [junit4] 2> 673745 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
> [junit4] 2> 673745 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr]
> [junit4] 2> 673745 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
> [junit4] 2> 673745 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
> [junit4] 2> 673747 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testExecute
> [junit4] 2> 673747 DEBUG (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
> [junit4] 2> 673748 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
> [junit4] 2> 673749 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
> [junit4] 2> 673749 DEBUG (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
> [junit4] 2> 673749 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
> [junit4] 2> java.lang.InterruptedException
> [junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220)
> [junit4] 2> at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335)
> [junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:154)
> [junit4] 2> at java.lang.Thread.run(Thread.java:748)
> [junit4] 2> 673750 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
> [junit4] 2> 673750 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
> [junit4] 2> 673750 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
> [junit4] 2> 673750 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion -1
> [junit4] 2> 673750 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
> [junit4] 2> 673750 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
> [junit4] 2> 673750 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
> [junit4] 2> 673751 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 673772 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 673796 DEBUG (ScheduledTrigger-2534-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 673816 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 673837 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 673860 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 673863 DEBUG (simCloudManagerPool-2533-thread-1) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testExecute
> [junit4] 2> 673876 DEBUG (simCloudManagerPool-2533-thread-1) [ ] o.a.s.c.Assign Identify nodes using default
> [junit4] 2> 673890 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 673909 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction Collection ready after 1372ms
> [junit4] 2> 673913 DEBUG (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.ExecutePlanAction -- processing event: {
> [junit4] 2> "id":"1505fce86a798140T33nqmts7exph1isszkrommojw",
> [junit4] 2> "source":"mock_trigger_name",
> [junit4] 2> "eventTime":1514894924829000000,
> [junit4] 2> "eventType":"NODELOST",
> [junit4] 2> "properties":{
> [junit4] 2> "eventTimes":[1514894924829000000],
> [junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}} with context properties: {operations=[org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@61774019, org.apache.solr.cloud.autoscaling.sim.TestExecutePlanAction$1@287f10fb]}
> [junit4] 2> 673913 DEBUG (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=MOVEREPLICA&collection=testExecute&targetNode=127.0.0.1:10000_solr&inPlaceMove=true&replica=core_node1
> [junit4] 2> 673915 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 673945 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 673975 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 674006 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 674017 DEBUG (simCloudManagerPool-2533-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- new replica: {"core_node4":{
> [junit4] 2> "core":"testExecute_shard1_replica_n3",
> [junit4] 2> "shard":"shard1",
> [junit4] 2> "collection":"testExecute",
> [junit4] 2> "node_name":"127.0.0.1:10000_solr",
> [junit4] 2> "type":"NRT"}}
> [junit4] 2> 674036 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 674066 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 674094 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 674117 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 674138 DEBUG (ScheduledTrigger-2534-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 674141 DEBUG (simCloudManagerPool-2533-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testExecute / shard1: {"core_node2":{
> [junit4] 2> "node_name":"127.0.0.1:10000_solr",
> [junit4] 2> "core":"testExecute_shard1_replica_n2",
> [junit4] 2> "leader":"true",
> [junit4] 2> "state":"active",
> [junit4] 2> "type":"NRT",
> [junit4] 2> "INDEX.sizeInBytes":123450000,
> [junit4] 2> "shard":"shard1",
> [junit4] 2> "collection":"testExecute"}}
> [junit4] 2> 674141 DEBUG (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=OVERSEERSTATUS
> [junit4] 2> 674148 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction Collection ready after 6ms
> [junit4] 2> 674148 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction -------------_ FINAL STATE --------------
> [junit4] 2> 674148 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction * Node values: {
> [junit4] 2> "127.0.0.1:10001_solr":{
> [junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
> [junit4] 2> "cores":0,
> [junit4] 2> "host":"127.0.0.1",
> [junit4] 2> "freedisk":1000,
> [junit4] 2> "sysprop.java.version":"1.8.0_144",
> [junit4] 2> "ip_1":"127",
> [junit4] 2> "ip_3":"0",
> [junit4] 2> "ip_2":"0",
> [junit4] 2> "ip_4":"1",
> [junit4] 2> "node":"127.0.0.1:10001_solr",
> [junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
> [junit4] 2> "port":10001,
> [junit4] 2> "heapUsage":123450000,
> [junit4] 2> "sysLoadAvg":1.0,
> [junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
> [junit4] 2> "127.0.0.1:10000_solr":{
> [junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
> [junit4] 2> "cores":2,
> [junit4] 2> "host":"127.0.0.1",
> [junit4] 2> "freedisk":980,
> [junit4] 2> "sysprop.java.version":"1.8.0_144",
> [junit4] 2> "ip_1":"127",
> [junit4] 2> "ip_3":"0",
> [junit4] 2> "ip_2":"0",
> [junit4] 2> "ip_4":"1",
> [junit4] 2> "node":"127.0.0.1:10000_solr",
> [junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
> [junit4] 2> "port":10000,
> [junit4] 2> "heapUsage":123450000,
> [junit4] 2> "sysLoadAvg":1.0,
> [junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}}
> [junit4] 2> 674148 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction * Live nodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
> [junit4] 2> 674149 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction * Collection testExecute state: DocCollection(testExecute//clusterstate.json/3)={
> [junit4] 2> "replicationFactor":"2",
> [junit4] 2> "pullReplicas":"0",
> [junit4] 2> "router":{"name":"compositeId"},
> [junit4] 2> "maxShardsPerNode":"1",
> [junit4] 2> "autoAddReplicas":"false",
> [junit4] 2> "nrtReplicas":"2",
> [junit4] 2> "tlogReplicas":"0",
> [junit4] 2> "autoCreated":"true",
> [junit4] 2> "shards":{"shard1":{
> [junit4] 2> "replicas":{
> [junit4] 2> "core_node2":{
> [junit4] 2> "core":"testExecute_shard1_replica_n2",
> [junit4] 2> "leader":"true",
> [junit4] 2> "INDEX.sizeInBytes":123450000,
> [junit4] 2> "node_name":"127.0.0.1:10000_solr",
> [junit4] 2> "state":"active",
> [junit4] 2> "type":"NRT"},
> [junit4] 2> "core_node4":{
> [junit4] 2> "node_name":"127.0.0.1:10000_solr",
> [junit4] 2> "core":"testExecute_shard1_replica_n3",
> [junit4] 2> "state":"active",
> [junit4] 2> "INDEX.sizeInBytes":123450000,
> [junit4] 2> "type":"NRT"}},
> [junit4] 2> "range":"80000000-7fffffff",
> [junit4] 2> "state":"active"}}}
> [junit4] 2> 674149 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testExecute
> [junit4] 2> 674149 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
> [junit4] 2>
> [junit4] 2> 674149 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
> [junit4] 2> 674149 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
> [junit4] 2> 674149 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
> [junit4] 2>
> [junit4] 2> 674149 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 2
> [junit4] 2> 674150 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 1
> [junit4] 2> 674150 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 0
> [junit4] 2> 674150 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: [testExecute]
> [junit4] 2> 674150 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 2
> [junit4] 2> 674151 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0
> [junit4] 2> 674151 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 2
> [junit4] 2> 674151 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * testExecute 2
> [junit4] 2> 674152 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - active 2
> [junit4] 2> 674152 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
> [junit4] 2> 674152 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - CREATE 1
> [junit4] 2> 674152 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - DELETESTATUS 2
> [junit4] 2> 674152 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - MOVEREPLICA 1
> [junit4] 2> 674152 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - OVERSEERSTATUS 1
> [junit4] 2> 674152 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - REQUESTSTATUS 2
> [junit4] 2> 674152 INFO (TEST-TestExecutePlanAction.testExecute-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
> [junit4] 2> 674156 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testIntegration
> [junit4] 2> 674156 DEBUG (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
> [junit4] 2> 674156 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
> [junit4] 2> 674156 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
> [junit4] 2> 674156 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
> [junit4] 2> 674157 DEBUG (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
> [junit4] 2> 674157 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
> [junit4] 2> 674157 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
> [junit4] 2> java.lang.InterruptedException
> [junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220)
> [junit4] 2> at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335)
> [junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:154)
> [junit4] 2> at java.lang.Thread.run(Thread.java:748)
> [junit4] 2> 674158 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
> [junit4] 2> 674158 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
> [junit4] 2> 674158 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
> [junit4] 2> 674158 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion -1
> [junit4] 2> 674158 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
> [junit4] 2> 674158 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
> [junit4] 2> 674158 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
> [junit4] 2> 674159 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 674189 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 674219 DEBUG (ScheduledTrigger-2537-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 674246 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 674268 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 674288 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 674309 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 674330 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 674335 DEBUG (simCloudManagerPool-2536-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
> [junit4] 2> 674335 DEBUG (simCloudManagerPool-2536-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
> [junit4] 2> 674336 DEBUG (simCloudManagerPool-2536-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
> [junit4] 2> 674336 DEBUG (simCloudManagerPool-2536-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
> [junit4] 2> 674336 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
> [junit4] 2> 674336 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
> [junit4] 2> 674336 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
> [junit4] 2> 674336 DEBUG (simCloudManagerPool-2536-thread-2) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testIntegration
> [junit4] 2> 674336 DEBUG (ScheduledTrigger-2537-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
> [junit4] 2> 674350 DEBUG (ScheduledTrigger-2537-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 674350 DEBUG (simCloudManagerPool-2536-thread-2) [ ] o.a.s.c.Assign Identify nodes using default
> [junit4] 2> 674360 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
> [junit4] 2> 674372 DEBUG (ScheduledTrigger-2537-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
> [junit4] 2> 674382 DEBUG (ScheduledTrigger-2537-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
> [junit4] 2> 674384 DEBUG (simCloudManagerPool-2536-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testIntegration / shard1: {"core_node1":{
> [junit4] 2> "node_name":"127.0.0.1:10001_solr",
> [junit4] 2> "core":"testIntegration_shard1_replica_n1",
> [junit4] 2> "leader":"true",
> [junit4] 2> "state":"active",
> [junit4] 2> "type":"NRT",
> [junit4] 2> "INDEX.sizeInBytes":123450000,
> [junit4] 2> "shard":"shard1",
> [junit4] 2> "collection":"testIntegration"}}
> [junit4] 2> 674392 DEBUG (ScheduledTrigger-2537-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
> [junit4] 2> 674392 DEBUG (ScheduledTrigger-2537-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10000_solr
> [junit4] 2> 674403 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 1
> [junit4] 2> 674403 DEBUG (ScheduledTrigger-2537-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10000_solr
> [junit4] 2> 674413 DEBUG (ScheduledTrigger-2537-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
> [junit4] 2> 674428 DEBUG (ScheduledTrigger-2537-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 1
> [junit4] 2> 674428 DEBUG (ScheduledTrigger-2537-thread-4) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10000_solr]
> [junit4] 2> 674429 DEBUG (ScheduledTrigger-2537-thread-4) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
> [junit4] 2> "id":"13f7ce395121f4T33nqmts7exph1isszkrommojx",
> [junit4] 2> "source":"node_lost_trigger",
> [junit4] 2> "eventTime":5620489654444532,
> [junit4] 2> "eventType":"NODELOST",
> [junit4] 2> "properties":{
> [junit4] 2> "eventTimes":[5620489654444532],
> [junit4] 2> "nodeNames":["127.0.0.1:10000_solr"]}}
> [junit4] 2> 674429 DEBUG (AutoscalingActionExecutor-2538-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
> [junit4] 2> "id":"13f7ce395121f4T33nqmts7exph1isszkrommojx",
> [junit4] 2> "source":"node_lost_trigger",
> [junit4] 2> "eventTime":5620489654444532,
> [junit4] 2> "eventType":"NODELOST",
> [junit4] 2> "properties":{
> [junit4] 2> "eventTimes":[5620489654444532],
> [junit4] 2> "_enqueue_time_":5620490924258232,
> [junit4] 2> "nodeNames":["127.0.0.1:10000_solr"]}}
> [junit4] 2> 674429 DEBUG (AutoscalingActionExecutor-2538-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
> [junit4] 2> "id":"13f7ce395121f4T33nqmts7exph1isszkrommojx",
> [junit4] 2> "source":"node_lost_trigger",
> [junit4] 2> "eventTime":5620489654444532,
> [junit4] 2> "eventType":"NODELOST",
> [junit4] 2> "properties":{
> [junit4] 2> "eventTimes":[5620489654444532],
> [junit4] 2> "_enqueue_time_":5620490924258232,
> [junit4] 2> "nodeNames":["127.0.0.1:10000_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
> [junit4] 2> 674431 INFO (AutoscalingActionExecutor-2538-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testIntegration&targetNode=127.0.0.1:10001_solr&inPlaceMove=true&replica=core_node2
> [junit4] 2> 674432 INFO (AutoscalingActionExecutor-2538-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 5620491088 sessionWrapper.createTime 5620491008758182, this.sessionWrapper.createTime 5620491008758182
> [junit4] 2> 674432 DEBUG (AutoscalingActionExecutor-2538-thread-1) [ ] o.a.s.c.a.ExecutePlanAction -- processing event: {
> [junit4] 2> "id":"13f7ce395121f4T33nqmts7exph1isszkrommojx",
> [junit4] 2> "source":"node_lost_trigger",
> [junit4] 2> "eventTime":5620489654444532,
> [junit4] 2> "eventType":"NODELOST",
> [junit4] 2> "properties":{
> [junit4] 2> "eventTimes":[5620489654444532],
> [junit4] 2> "_enqueue_time_":5620490924258232,
> [junit4] 2> "nodeNames":["127.0.0.1:10000_solr"]}} with context properties: {operations=[org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@1c4d6e44], AFTER_ACTION=[compute_plan], BEFORE_ACTION=[compute_plan, execute_plan]}
> [junit4] 2> 674432 DEBUG (AutoscalingActionExecutor-2538-thread-1) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=MOVEREPLICA&collection=testIntegration&targetNode=127.0.0.1:10001_solr&inPlaceMove=true&replica=core_node2
> [junit4] 2> 674533 DEBUG (simCloudManagerPool-2536-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- new replica: {"core_node4":{
> [junit4] 2> "core":"testIntegration_shard1_replica_n3",
> [junit4] 2> "shard":"shard1",
> [junit4] 2> "collection":"testIntegration",
> [junit4] 2> "node_name":"127.0.0.1:10001_solr",
> [junit4] 2> "type":"NRT"}}
> [junit4] 2> 674650 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction -------------_ FINAL STATE --------------
> [junit4] 2> 674650 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction * Node values: {
> [junit4] 2> "127.0.0.1:10001_solr":{
> [junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
> [junit4] 2> "cores":2,
> [junit4] 2> "host":"127.0.0.1",
> [junit4] 2> "freedisk":980,
> [junit4] 2> "sysprop.java.version":"1.8.0_144",
> [junit4] 2> "ip_1":"127",
> [junit4] 2> "ip_3":"0",
> [junit4] 2> "ip_2":"0",
> [junit4] 2> "ip_4":"1",
> [junit4] 2> "node":"127.0.0.1:10001_solr",
> [junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
> [junit4] 2> "port":10001,
> [junit4] 2> "heapUsage":123450000,
> [junit4] 2> "sysLoadAvg":1.0,
> [junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
> [junit4] 2> "127.0.0.1:10000_solr":{
> [junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
> [junit4] 2> "cores":1,
> [junit4] 2> "host":"127.0.0.1",
> [junit4] 2> "freedisk":970,
> [junit4] 2> "sysprop.java.version":"1.8.0_144",
> [junit4] 2> "ip_1":"127",
> [junit4] 2> "ip_3":"0",
> [junit4] 2> "ip_2":"0",
> [junit4] 2> "ip_4":"1",
> [junit4] 2> "node":"127.0.0.1:10000_solr",
> [junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
> [junit4] 2> "port":10000,
> [junit4] 2> "heapUsage":123450000,
> [junit4] 2> "sysLoadAvg":1.0,
> [junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}}
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction * Live nodes: [127.0.0.1:10001_solr]
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.TestExecutePlanAction * Collection testIntegration state: DocCollection(testIntegration//clusterstate.json/10)={
> [junit4] 2> "replicationFactor":"2",
> [junit4] 2> "pullReplicas":"0",
> [junit4] 2> "router":{"name":"compositeId"},
> [junit4] 2> "maxShardsPerNode":"1",
> [junit4] 2> "autoAddReplicas":"false",
> [junit4] 2> "nrtReplicas":"2",
> [junit4] 2> "tlogReplicas":"0",
> [junit4] 2> "autoCreated":"true",
> [junit4] 2> "shards":{"shard1":{
> [junit4] 2> "replicas":{
> [junit4] 2> "core_node1":{
> [junit4] 2> "core":"testIntegration_shard1_replica_n1",
> [junit4] 2> "leader":"true",
> [junit4] 2> "INDEX.sizeInBytes":123450000,
> [junit4] 2> "node_name":"127.0.0.1:10001_solr",
> [junit4] 2> "state":"active",
> [junit4] 2> "type":"NRT"},
> [junit4] 2> "core_node4":{
> [junit4] 2> "node_name":"127.0.0.1:10001_solr",
> [junit4] 2> "core":"testIntegration_shard1_replica_n3",
> [junit4] 2> "state":"active",
> [junit4] 2> "INDEX.sizeInBytes":123450000,
> [junit4] 2> "type":"NRT"}},
> [junit4] 2> "range":"80000000-7fffffff",
> [junit4] 2> "state":"active"}}}
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testIntegration
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
> [junit4] 2>
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
> [junit4] 2>
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 1
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 0
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 1
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## 127.0.0.1:10000_solr
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: [testIntegration]
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 2
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 2
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 2
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * testIntegration 2
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - active 2
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - CREATE 1
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - DELETESTATUS 1
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - MOVEREPLICA 1
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - REQUESTSTATUS 1
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 1
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 1
> [junit4] 2> 674651 INFO (TEST-TestExecutePlanAction.testIntegration-seed#[DB943222460F3A98]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
> [junit4] 2> 674651 DEBUG (AutoscalingActionExecutor-2538-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 11101 ms for event id=13f7ce395121f4T33nqmts7exph1isszkrommojx
> [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestExecutePlanAction -Dtests.method=testIntegration -Dtests.seed=DB943222460F3A98 -Dtests.slow=true -Dtests.locale=sv -Dtests.timezone=Africa/Porto-Novo -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
> [junit4] ERROR 0.50s J0 | TestExecutePlanAction.testIntegration <<<
> [junit4] > Throwable #1: java.util.ConcurrentModificationException
> [junit4] > at __randomizedtesting.SeedInfo.seed([DB943222460F3A98:6BF53C0E63309BBD]:0)
> [junit4] > at java.util.ArrayList$Itr.checkForComodification(ArrayList.java:901)
> [junit4] > at java.util.ArrayList$Itr.next(ArrayList.java:851)
> [junit4] > at org.apache.solr.cloud.autoscaling.sim.SimSolrCloudTestCase.tearDown(SimSolrCloudTestCase.java:141)
> [junit4] > at java.lang.Thread.run(Thread.java:748)
> [junit4] 2> 674654 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
> [junit4] 2> 674654 DEBUG (SUITE-TestExecutePlanAction-seed#[DB943222460F3A98]-worker) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
> [junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestExecutePlanAction_DB943222460F3A98-001
> [junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=839, maxMBSortInHeap=5.924442087858636, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@6fef801c), locale=sv, timezone=Africa/Porto-Novo
> [junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=3,threads=1,free=218802608,total=536870912
> [junit4] 2> NOTE: All tests run in this JVM: [ResponseLogComponentTest, SpellCheckCollatorTest, TestSolrConfigHandlerConcurrent, CursorPagingTest, EnumFieldTest, TestBinaryField, TestComplexPhraseQParserPlugin, AtomicUpdateProcessorFactoryTest, MultiTermTest, NotRequiredUniqueKeyTest, TestIBSimilarityFactory, TestSweetSpotSimilarityFactory, TestMaxScoreQueryParser, BlobRepositoryCloudTest, TestCopyFieldCollectionResource, TestDynamicFieldResource, DirectUpdateHandlerTest, TestManagedResource, TestOrdValues, TestAuthenticationFramework, CdcrVersionReplicationTest, BigEndianAscendingWordSerializerTest, SolrCloudExampleTest, UnloadDistributedZkTest, TestCoreBackup, RegexBytesRefFilterTest, SuggesterTest, InfixSuggestersTest, TestDFRSimilarityFactory, TestDistribIDF, TestUseDocValuesAsStored, HdfsWriteToMultipleCollectionsTest, TestRandomCollapseQParserPlugin, TestXIncludeConfig, TestFieldCacheVsDocValues, RequiredFieldsTest, SpatialRPTFieldTypeTest, TestSolrCoreProperties, PeerSyncWithIndexFingerprintCachingTest, TestFieldCacheSort, TestFiltering, TestRawResponseWriter, DistanceUnitsTest, SSLMigrationTest, TestRestoreCore, TestCloudInspectUtil, TestCursorMarkWithoutUniqueKey, TestRandomDVFaceting, BJQParserTest, TestFieldTypeResource, DeleteInactiveReplicaTest, TestLFUCache, TestLockTree, TestStressLiveNodes, MissingSegmentRecoveryTest, TestQuerySenderListener, SegmentsInfoRequestHandlerTest, SyncSliceTest, CircularListTest, TestHdfsUpdateLog, HdfsTlogReplayBufferedWhileIndexingTest, CreateCollectionCleanupTest, TestDistributedStatsComponentCardinality, TestStressCloudBlindAtomicUpdates, TestTolerantUpdateProcessorCloud, TestXmlQParser, TestSchemaVersionResource, TestLegacyField, DocExpirationUpdateProcessorFactoryTest, TestLMDirichletSimilarityFactory, TestInPlaceUpdatesStandalone, TestScoreJoinQPScore, TestFreeTextSuggestions, BasicAuthIntegrationTest, TestSurroundQueryParser, TestMultiWordSynonyms, LegacyCloudClusterPropTest, TestSha256AuthenticationProvider, TestZkAclsWithHadoopAuth, DistributedFacetPivotLongTailTest, TestHttpShardHandlerFactory, TestCustomDocTransformer, ChaosMonkeyNothingIsSafeTest, TestReloadDeadlock, CoreSorterTest, ZkStateWriterTest, TestNonDefinedSimilarityFactory, LeaderFailoverAfterPartitionTest, DistributedDebugComponentTest, TestExecutePlanAction]
> [junit4] Completed [164/765 (1!)] on J0 in 0.94s, 2 tests, 1 error <<< FAILURES!
>
> [...truncated 9343 lines...]
> [junit4] Suite: org.apache.solr.ltr.TestLTRQParserExplain
> [junit4] 2> 49795 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
> [junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/init-core-data-001
> [junit4] 2> 49797 WARN (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=24 numCloses=24
> [junit4] 2> 49797 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
> [junit4] 2> 49801 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) w/ MAC_OS_X supressed clientAuth
> [junit4] 2> 49802 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore
> [junit4] 2> 49818 WARN (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.c.SolrConfig Couldn't add files from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/contrib/ltr/src/test-files/solr/models filtered by null to classpath: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/contrib/ltr/src/test-files/solr/models
> [junit4] 2> 49827 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
> [junit4] 2> 49838 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.s.IndexSchema [null] Schema name=example
> [junit4] 2> 49849 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.s.IndexSchema Loaded schema example/1.5 with uniqueid field id
> [junit4] 2> 49941 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e063592
> [junit4] 2> 49961 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e063592
> [junit4] 2> 49962 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e063592
> [junit4] 2> 49964 INFO (coreLoadExecutor-329-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
> [junit4] 2> 49979 WARN (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.c.SolrConfig Couldn't add files from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/contrib/ltr/src/test-files/solr/models filtered by null to classpath: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/contrib/ltr/src/test-files/solr/models
> [junit4] 2> 49981 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
> [junit4] 2> 49991 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=example
> [junit4] 2> 50016 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema example/1.5 with uniqueid field id
> [junit4] 2> 50019 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/contrib/ltr/src/test-files/solr/collection1, trusted=true
> [junit4] 2> 50019 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e063592
> [junit4] 2> 50019 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
> [junit4] 2> 50019 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/contrib/ltr/src/test-files/solr/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/init-core-data-001/]
> [junit4] 2> 50131 WARN (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.c.RequestHandlers no default request handler is registered (either '/select' or 'standard')
> [junit4] 2> 50132 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
> [junit4] 2> 50132 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
> [junit4] 2> 50163 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms;
> [junit4] 2> 50163 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: if uncommited for 1000ms;
> [junit4] 2> 50167 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@436f5833[collection1] main]
> [junit4] 2> 50167 WARN (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage Cannot write to config directory /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/contrib/ltr/src/test-files/solr/collection1/conf; switching to use InMemory storage instead.
> [junit4] 2> 50167 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.r.RestManager Registered ManagedResource impl org.apache.solr.ltr.store.rest.ManagedFeatureStore for path /schema/feature-store
> [junit4] 2> 50167 WARN (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.r.ManagedResource No stored data found for /schema/feature-store
> [junit4] 2> 50167 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore ------ managed feature ~ loading ------
> [junit4] 2> 50167 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.r.ManagedResource Notified 1 observers of /schema/feature-store
> [junit4] 2> 50167 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.r.RestManager Registered new managed resource /schema/feature-store
> [junit4] 2> 50167 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.r.RestManager Registered ManagedResource impl org.apache.solr.ltr.store.rest.ManagedModelStore for path /schema/model-store
> [junit4] 2> 50168 WARN (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.r.ManagedResource No stored data found for /schema/model-store
> [junit4] 2> 50168 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.l.s.r.ManagedModelStore INIT model store
> [junit4] 2> 50168 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.l.s.r.ManagedModelStore ------ managed models ~ loading ------
> [junit4] 2> 50168 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.r.ManagedResource Notified 1 observers of /schema/model-store
> [junit4] 2> 50168 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.r.RestManager Registered new managed resource /schema/model-store
> [junit4] 2> 50168 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
> [junit4] 2> 50170 INFO (searcherExecutor-330-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@436f5833[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
> [junit4] 2> 50171 INFO (coreLoadExecutor-329-thread-1) [ x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1588486125193789440
> [junit4] 2> 50176 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end
> [junit4] 2> 50186 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore
> [junit4] 2> 50186 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end
> [junit4] 2> 50187 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-003/cores/core
> [junit4] 2> 50189 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
> [junit4] 2> 50191 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3399363e{/solr,null,AVAILABLE}
> [junit4] 2> 50192 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3795cdb7{HTTP/1.1,[http/1.1]}{127.0.0.1:53047}
> [junit4] 2> 50192 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.e.j.s.Server Started @53029ms
> [junit4] 2> 50192 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=53047, configSetBaseDir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-001, coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-003/cores}
> [junit4] 2> 50193 ERROR (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
> [junit4] 2> 50193 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
> [junit4] 2> 50193 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
> [junit4] 2> 50193 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
> [junit4] 2> 50194 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-02T13:06:59.587Z
> [junit4] 2> 50194 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-001/solr.xml
> [junit4] 2> 50301 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@6e063592, but no JMX reporters were configured - adding default JMX reporter.
> [junit4] 2> 50472 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e063592
> [junit4] 2> 50503 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e063592
> [junit4] 2> 50517 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e063592
> [junit4] 2> 50524 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-003/cores
> [junit4] 2> 50524 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
> [junit4] 2> 50528 INFO (coreLoadExecutor-340-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
> [junit4] 2> 50577 WARN (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.c.SolrConfig Couldn't add files from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-001/models filtered by null to classpath: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-001/models
> [junit4] 2> 50580 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
> [junit4] 2> 50658 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=example
> [junit4] 2> 50669 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema example/1.5 with uniqueid field id
> [junit4] 2> 50683 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from configset /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-001/collection1, trusted=true
> [junit4] 2> 50693 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e063592
> [junit4] 2> 50693 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
> [junit4] 2> 50693 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-001/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-003/cores/core/data/]
> [junit4] 2> 50886 WARN (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.c.RequestHandlers no default request handler is registered (either '/select' or 'standard')
> [junit4] 2> 50887 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
> [junit4] 2> 50887 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
> [junit4] 2> 50890 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms;
> [junit4] 2> 50890 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: if uncommited for 1000ms;
> [junit4] 2> 50929 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4b836e02[collection1] main]
> [junit4] 2> 50930 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-001/collection1/conf
> [junit4] 2> 50931 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.r.RestManager Registered ManagedResource impl org.apache.solr.ltr.store.rest.ManagedFeatureStore for path /schema/feature-store
> [junit4] 2> 50931 WARN (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.r.ManagedResource No stored data found for /schema/feature-store
> [junit4] 2> 50931 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore ------ managed feature ~ loading ------
> [junit4] 2> 50931 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.r.ManagedResource Notified 1 observers of /schema/feature-store
> [junit4] 2> 50931 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.r.RestManager Registered new managed resource /schema/feature-store
> [junit4] 2> 50931 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.r.RestManager Registered ManagedResource impl org.apache.solr.ltr.store.rest.ManagedModelStore for path /schema/model-store
> [junit4] 2> 50932 WARN (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.r.ManagedResource No stored data found for /schema/model-store
> [junit4] 2> 50932 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.l.s.r.ManagedModelStore INIT model store
> [junit4] 2> 50932 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.l.s.r.ManagedModelStore ------ managed models ~ loading ------
> [junit4] 2> 50932 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.r.ManagedResource Notified 1 observers of /schema/model-store
> [junit4] 2> 50932 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.r.RestManager Registered new managed resource /schema/model-store
> [junit4] 2> 50933 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
> [junit4] 2> 50933 INFO (coreLoadExecutor-340-thread-1) [ x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1588486125992804352
> [junit4] 2> 50936 INFO (searcherExecutor-341-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@4b836e02[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
> [junit4] 2> 50937 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrJettyTestBase Jetty Assigned Port#53047
> [junit4] 2> 50961 INFO (qtp511526317-485) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={stream.body=<add><doc><field+name%3D"title">bloomberg+different+bla</field><field+name%3D"description">bloomberg</field><field+name%3D"id">6</field><field+name%3D"popularity">1</field></doc></add>}{add=[6 (1588486126007484416)]} 0 15
> [junit4] 2> 50971 INFO (qtp511526317-486) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={stream.body=<add><doc><field+name%3D"title">bloomberg+bloomberg+</field><field+name%3D"description">bloomberg</field><field+name%3D"id">7</field><field+name%3D"popularity">2</field></doc></add>}{add=[7 (1588486126030553088)]} 0 3
> [junit4] 2> 50975 INFO (qtp511526317-487) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={stream.body=<add><doc><field+name%3D"title">bloomberg+bloomberg+bloomberg</field><field+name%3D"description">bloomberg</field><field+name%3D"id">8</field><field+name%3D"popularity">3</field></doc></add>}{add=[8 (1588486126035795968)]} 0 1
> [junit4] 2> 50982 INFO (qtp511526317-488) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={stream.body=<add><doc><field+name%3D"title">bloomberg+bloomberg+bloomberg+bloomberg</field><field+name%3D"description">bloomberg</field><field+name%3D"id">9</field><field+name%3D"popularity">5</field></doc></add>}{add=[9 (1588486126043136000)]} 0 1
> [junit4] 2> 50985 INFO (qtp511526317-489) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1588486126047330304,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
> [junit4] 2> 50985 INFO (qtp511526317-489) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@212b3cf commitCommandVersion:1588486126047330304
> [junit4] 2> 51172 INFO (qtp511526317-489) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@598abb28[collection1] main]
> [junit4] 2> 51173 INFO (qtp511526317-489) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
> [junit4] 2> 51176 INFO (searcherExecutor-341-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@598abb28[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C4)))}
> [junit4] 2> 51177 INFO (qtp511526317-489) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={stream.body=<commit/>}{commit=} 0 192
> [junit4] 2> 51185 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.l.TestRerankBase send
> [junit4] 2> [
> [junit4] 2> {
> [junit4] 2> "name": "constant1",
> [junit4] 2> "class": "org.apache.solr.ltr.feature.ValueFeature",
> [junit4] 2> "store":"test",
> [junit4] 2> "params": {
> [junit4] 2> "value": 1
> [junit4] 2> }
> [junit4] 2> },
> [junit4] 2> {
> [junit4] 2> "name": "constant2",
> [junit4] 2> "class": "org.apache.solr.ltr.feature.ValueFeature",
> [junit4] 2> "store":"test",
> [junit4] 2> "params": {
> [junit4] 2> "value": 2
> [junit4] 2> }
> [junit4] 2> },
> [junit4] 2> {
> [junit4] 2> "name": "constant3",
> [junit4] 2> "class": "org.apache.solr.ltr.feature.ValueFeature",
> [junit4] 2> "store":"test",
> [junit4] 2> "params": {
> [junit4] 2> "value": 3
> [junit4] 2> }
> [junit4] 2> },
> [junit4] 2> {
> [junit4] 2> "name": "constant4",
> [junit4] 2> "class": "org.apache.solr.ltr.feature.ValueFeature",
> [junit4] 2> "store":"test",
> [junit4] 2> "params": {
> [junit4] 2> "value": 4
> [junit4] 2> }
> [junit4] 2> },
> [junit4] 2> {
> [junit4] 2> "name": "constant5",
> [junit4] 2> "class": "org.apache.solr.ltr.feature.ValueFeature",
> [junit4] 2> "store":"test",
> [junit4] 2> "params": {
> [junit4] 2> "value": 5
> [junit4] 2> }
> [junit4] 2> },
> [junit4] 2> {
> [junit4] 2> "name": "pop",
> [junit4] 2> "class": "org.apache.solr.ltr.feature.FieldValueFeature",
> [junit4] 2> "store":"test",
> [junit4] 2> "params": {
> [junit4] 2> "field": "popularity"
> [junit4] 2> }
> [junit4] 2> }
> [junit4] 2>
> [junit4] 2> ]
> [junit4] 2>
> [junit4] 2> 51187 INFO (qtp511526317-490) [ x:collection1] /solr SolrSchemaRestApi: [Restlet] ServerServlet: component class is null
> [junit4] 2> 51188 INFO (qtp511526317-490) [ x:collection1] /solr SolrSchemaRestApi: [Restlet] Attaching application: org.apache.solr.rest.SolrSchemaRestApi@a5c75eb to URI: /solr/schema
> [junit4] 2> Jan 02, 2018 8:07:00 AM org.restlet.Application start
> [junit4] 2> INFO: Starting org.apache.solr.rest.SolrSchemaRestApi application
> [junit4] 2> 51211 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.SolrSchemaRestApi createInboundRoot started for /schema
> [junit4] 2> 51211 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.RestManager Attached managed resource at path: /feature-store
> [junit4] 2> 51211 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.RestManager Attached managed resource at path: /managed
> [junit4] 2> 51212 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.RestManager Attached managed resource at path: /model-store
> [junit4] 2> 51212 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.RestManager Attached 3 ManagedResource endpoints to Restlet router: /schema
> [junit4] 2> 51212 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.SolrSchemaRestApi createInboundRoot complete for /schema
> [junit4] 2> 51212 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.RestManager Found ManagedResource [org.apache.solr.ltr.store.rest.ManagedFeatureStore@3ad3c526] for /schema/feature-store
> [junit4] 2> 51213 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.ManagedResource Processing update to /schema/feature-store: [{name=constant1, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=1}}, {name=constant2, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=2}}, {name=constant3, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=3}}, {name=constant4, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=4}}, {name=constant5, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=5}}, {name=pop, class=org.apache.solr.ltr.feature.FieldValueFeature, store=test, params={field=popularity}}] is a java.util.ArrayList
> [junit4] 2> 51213 INFO (qtp511526317-490) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore register feature based on {name=constant1, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=1}}
> [junit4] 2> 51253 INFO (qtp511526317-490) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore register feature based on {name=constant2, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=2}}
> [junit4] 2> 51253 INFO (qtp511526317-490) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore register feature based on {name=constant3, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=3}}
> [junit4] 2> 51253 INFO (qtp511526317-490) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore register feature based on {name=constant4, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=4}}
> [junit4] 2> 51254 INFO (qtp511526317-490) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore register feature based on {name=constant5, class=org.apache.solr.ltr.feature.ValueFeature, store=test, params={value=5}}
> [junit4] 2> 51254 INFO (qtp511526317-490) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore register feature based on {name=pop, class=org.apache.solr.ltr.feature.FieldValueFeature, store=test, params={field=popularity}}
> [junit4] 2> 51267 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.ManagedResourceStorage Saved JSON object to path _schema_feature-store.json using file:dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-001/collection1/conf
> [junit4] 2> 51268 INFO (qtp511526317-490) [ x:collection1] o.a.s.r.RestManager [collection1] webapp=/solr path=/schema/feature-store params={indent=on&wt=json} status=0 QTime=81
> [junit4] 2> Jan 02, 2018 8:07:00 AM org.restlet.engine.log.LogFilter afterHandle
> [junit4] 2> INFO: 2018-01-02 08:07:00 127.0.0.1 - 127.0.0.1 53047 PUT /solr/schema/feature-store wt=json&indent=on 200 - 1077 79 http://127.0.0.1:53047 Apache-HttpClient/4.5.3 (Java/1.8.0_144) -
> [junit4] 2> 51269 WARN (qtp511526317-490) [ x:collection1] o.e.j.s.ServletHandler Error for /solr/collection1/schema/feature-store
> [junit4] 2> java.lang.AssertionError: Attempted close of response output stream.
> [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter$2$1.close(SolrDispatchFilter.java:525)
> [junit4] 2> at org.eclipse.jetty.server.Dispatcher.commitResponse(Dispatcher.java:270)
> [junit4] 2> at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:202)
> [junit4] 2> at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:74)
> [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:391)
> [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:326)
> [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
> [junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139)
> [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
> [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
> [junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
> [junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
> [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
> [junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
> [junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
> [junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
> [junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:426)
> [junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
> [junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534)
> [junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
> [junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
> [junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
> [junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
> [junit4] 2> at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
> [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
> [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
> [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
> [junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
> [junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
> [junit4] 2> at java.lang.Thread.run(Thread.java:748)
> [junit4] 2> 51278 INFO (TEST-TestLTRQParserExplain.multipleAdditiveTreesScoreExplainMissingEfiFeatureShouldReturnDefaultScore-seed#[BF50F24C695B12A1]) [ ] o.a.s.SolrTestCaseJ4 ###Starting multipleAdditiveTreesScoreExplainMissingEfiFeatureShouldReturnDefaultScore
> [junit4] 2> 51279 INFO (TEST-TestLTRQParserExplain.multipleAdditiveTreesScoreExplainMissingEfiFeatureShouldReturnDefaultScore-seed#[BF50F24C695B12A1]) [ ] o.a.s.l.TestRerankBase send
> [junit4] 2> [{
> [junit4] 2> "name" : "user_device_smartphone",
> [junit4] 2> "class":"org.apache.solr.ltr.feature.ValueFeature",
> [junit4] 2> "params" : {
> [junit4] 2> "value": "${user_device_smartphone}"
> [junit4] 2> }
> [junit4] 2> },
> [junit4] 2> {
> [junit4] 2> "name" : "user_device_tablet",
> [junit4] 2> "class":"org.apache.solr.ltr.feature.ValueFeature",
> [junit4] 2> "params" : {
> [junit4] 2> "value": "${user_device_tablet}"
> [junit4] 2> }
> [junit4] 2> }
> [junit4] 2>
> [junit4] 2>
> [junit4] 2>
> [junit4] 2> ]
> [junit4] 2>
> [junit4] 2> 51282 INFO (qtp511526317-483) [ x:collection1] o.a.s.r.RestManager Found ManagedResource [org.apache.solr.ltr.store.rest.ManagedFeatureStore@3ad3c526] for /schema/feature-store
> [junit4] 2> 51282 INFO (qtp511526317-483) [ x:collection1] o.a.s.r.ManagedResource Processing update to /schema/feature-store: [{name=user_device_smartphone, class=org.apache.solr.ltr.feature.ValueFeature, params={value=${user_device_smartphone}}}, {name=user_device_tablet, class=org.apache.solr.ltr.feature.ValueFeature, params={value=${user_device_tablet}}}] is a java.util.ArrayList
> [junit4] 2> 51282 INFO (qtp511526317-483) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore register feature based on {name=user_device_smartphone, class=org.apache.solr.ltr.feature.ValueFeature, params={value=${user_device_smartphone}}}
> [junit4] 2> 51282 INFO (qtp511526317-483) [ x:collection1] o.a.s.l.s.r.ManagedFeatureStore register feature based on {name=user_device_tablet, class=org.apache.solr.ltr.feature.ValueFeature, params={value=${user_device_tablet}}}
> [junit4] 2> 51283 INFO (qtp511526317-483) [ x:collection1] o.a.s.r.ManagedResourceStorage Saved JSON object to path _schema_feature-store.json using file:dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001/tempDir-001/collection1/conf
> [junit4] 2> 51283 INFO (qtp511526317-483) [ x:collection1] o.a.s.r.RestManager [collection1] webapp=/solr path=/schema/feature-store params={indent=on&wt=json} status=0 QTime=3
> [junit4] 2> Jan 02, 2018 8:07:00 AM org.restlet.engine.log.LogFilter afterHandle
> [junit4] 2> INFO: 2018-01-02 08:07:00 127.0.0.1 - 127.0.0.1 53047 PUT /solr/schema/feature-store wt=json&indent=on 200 - 323 2 http://127.0.0.1:53047 Apache-HttpClient/4.5.3 (Java/1.8.0_144) -
> [junit4] 2> 51284 WARN (qtp511526317-483) [ x:collection1] o.e.j.s.ServletHandler Error for /solr/collection1/schema/feature-store
> [junit4] 2> java.lang.AssertionError: Attempted close of response output stream.
> [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter$2$1.close(SolrDispatchFilter.java:525)
> [junit4] 2> at org.eclipse.jetty.server.Dispatcher.commitResponse(Dispatcher.java:270)
> [junit4] 2> at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:202)
> [junit4] 2> at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:74)
> [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:391)
> [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:326)
> [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
> [junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139)
> [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
> [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
> [junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
> [junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
> [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
> [junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
> [junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
> [junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
> [junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:426)
> [junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
> [junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534)
> [junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
> [junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
> [junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
> [junit4] 2> at org.eclipse.jetty.io.FillInterest.
>
> [...truncated too long message...]
>
> mitResponse(Dispatcher.java:270)
> [junit4] 2> at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:202)
> [junit4] 2> at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:74)
> [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:391)
> [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:326)
> [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
> [junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139)
> [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
> [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
> [junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
> [junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
> [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
> [junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
> [junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
> [junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
> [junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:426)
> [junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
> [junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534)
> [junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
> [junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
> [junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
> [junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
> [junit4] 2> at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
> [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
> [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
> [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
> [junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
> [junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
> [junit4] 2> at java.lang.Thread.run(Thread.java:748)
> [junit4] 2> 51497 INFO (qtp511526317-488) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/query params={q=title:bloomberg&indent=on&fl=*,score&rows=4&wt=json&debugQuery=on&rq={!ltr+reRankDocs%3D4+model%3Dlinear-efi}} hits=4 status=0 QTime=2
> [junit4] 2> 51501 INFO (qtp511526317-489) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/query params={q=title:bloomberg&indent=on&fl=*,score&rows=4&wt=json&debugQuery=on&rq={!ltr+reRankDocs%3D4+model%3Dlinear-efi}} hits=4 status=0 QTime=2
> [junit4] 2> 51502 INFO (TEST-TestLTRQParserExplain.LinearScoreExplainMissingEfiFeatureShouldReturnDefaultScore-seed#[BF50F24C695B12A1]) [ ] o.a.s.SolrTestCaseJ4 ###Ending LinearScoreExplainMissingEfiFeatureShouldReturnDefaultScore
> [junit4] 2> 51504 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@3795cdb7{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
> [junit4] 2> 51504 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=322867989
> [junit4] 2> 51504 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
> [junit4] 2> 51504 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3cb2da54: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@1f9092bf
> [junit4] 2> 51514 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
> [junit4] 2> 51514 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@14ecc590: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@6e6a01b9
> [junit4] 2> 51521 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
> [junit4] 2> 51521 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4a6f3ed6: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@6a5598ac
> [junit4] 2> 51523 INFO (coreCloseExecutor-346-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@31fc24c5
> [junit4] 2> 51523 INFO (coreCloseExecutor-346-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=838608069
> [junit4] 2> 51523 INFO (coreCloseExecutor-346-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@573053f4: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@7fcb7594
> [junit4] 2> 51551 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@3399363e{/solr,null,UNAVAILABLE}
> [junit4] 2> 51573 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
> [junit4] 2> 51573 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1918236122
> [junit4] 2> 51573 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
> [junit4] 2> 51573 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4ab04e5b: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@6987c674
> [junit4] 2> 51574 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
> [junit4] 2> 51574 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@720828e1: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@6e6a01b9
> [junit4] 2> 51575 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
> [junit4] 2> 51575 INFO (SUITE-TestLTRQParserExplain-seed#[BF50F24C695B12A1]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1871c8a5: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@6a5598ac
> [junit4] 2> 51576 INFO (coreCloseExecutor-348-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@46946a09
> [junit4] 2> 51576 INFO (coreCloseExecutor-348-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=1184131593
> [junit4] 2> 51576 INFO (coreCloseExecutor-348-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3717fa34: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@495237ee
> [junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-ltr/test/J0/temp/solr.ltr.TestLTRQParserExplain_BF50F24C695B12A1-001
> [junit4] 2> NOTE: test params are: codec=Lucene70, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@6b4359a7), locale=en-GB, timezone=America/Montreal
> [junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=3,threads=1,free=106751488,total=198180864
> [junit4] 2> NOTE: All tests run in this JVM: [TestModelManagerPersistence, TestRerankBase, TestMultipleAdditiveTreesModel, TestOriginalScoreScorer, TestFeatureLogging, TestExternalValueFeatures, TestUserTermScoreWithQ, TestFieldValueFeature, TestEdisMaxSolrFeature, TestLTROnSolrCloud, TestLTRQParserExplain]
> [junit4] Completed [20/35 (1!)] on J0 in 1.83s, 4 tests, 1 error <<< FAILURES!
>
> [...truncated 40705 lines...]
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org