Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/19907/ Java: 64bit/jdk1.8.0_131 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed. FAILED: org.apache.solr.client.solrj.io.stream.StreamExpressionTest.testArraySort Error Message: --> https://127.0.0.1:43665/solr/collection1:Invalid stream expression arraySort(array(11.5,12.3,4,3,1,0)) - function 'arraySort' is unknown (not mapped to a valid TupleStream) Stack Trace: java.io.IOException: --> https://127.0.0.1:43665/solr/collection1:Invalid stream expression arraySort(array(11.5,12.3,4,3,1,0)) - function 'arraySort' is unknown (not mapped to a valid TupleStream) at __randomizedtesting.SeedInfo.seed([F2D6CCEA47D3CAF9:C4601AC7C00A3680]:0) at org.apache.solr.client.solrj.io.stream.SolrStream.read(SolrStream.java:219) at org.apache.solr.client.solrj.io.stream.StreamExpressionTest.getTuples(StreamExpressionTest.java:7487) at org.apache.solr.client.solrj.io.stream.StreamExpressionTest.testArraySort(StreamExpressionTest.java:5840) 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:1713) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957) 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:916) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) 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 14105 lines...] [junit4] Suite: org.apache.solr.client.solrj.io.stream.StreamExpressionTest [junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.io.stream.StreamExpressionTest_F2D6CCEA47D3CAF9-001/init-core-data-001 [junit4] 2> 74951 WARN (SUITE-StreamExpressionTest-seed#[F2D6CCEA47D3CAF9]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=4 numCloses=4 [junit4] 2> 74951 INFO (SUITE-StreamExpressionTest-seed#[F2D6CCEA47D3CAF9]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields [junit4] 2> 74952 INFO (SUITE-StreamExpressionTest-seed#[F2D6CCEA47D3CAF9]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) [junit4] 2> 74953 INFO (SUITE-StreamExpressionTest-seed#[F2D6CCEA47D3CAF9]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.io.stream.StreamExpressionTest_F2D6CCEA47D3CAF9-001/tempDir-001 [junit4] 2> 74953 INFO (SUITE-StreamExpressionTest-seed#[F2D6CCEA47D3CAF9]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 74953 INFO (Thread-476) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 74953 INFO (Thread-476) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 74954 ERROR (Thread-476) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes [junit4] 2> 75053 INFO (SUITE-StreamExpressionTest-seed#[F2D6CCEA47D3CAF9]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:41525 [junit4] 2> 75064 INFO (jetty-launcher-241-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 75065 INFO (jetty-launcher-241-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 75068 INFO (jetty-launcher-241-thread-3) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 75073 INFO (jetty-launcher-241-thread-4) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 75087 INFO (jetty-launcher-241-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7f9741a8{/solr,null,AVAILABLE} [junit4] 2> 75090 INFO (jetty-launcher-241-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7ab783a2{/solr,null,AVAILABLE} [junit4] 2> 75096 INFO (jetty-launcher-241-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2adf85c8{SSL,[ssl, http/1.1]}{127.0.0.1:39523} [junit4] 2> 75096 INFO (jetty-launcher-241-thread-3) [ ] o.e.j.s.Server Started @77092ms [junit4] 2> 75096 INFO (jetty-launcher-241-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39523} [junit4] 2> 75096 ERROR (jetty-launcher-241-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 75096 INFO (jetty-launcher-241-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0 [junit4] 2> 75096 INFO (jetty-launcher-241-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 75096 INFO (jetty-launcher-241-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 75096 INFO (jetty-launcher-241-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-06-19T12:29:59.498Z [junit4] 2> 75100 INFO (jetty-launcher-241-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1e2f3a53{SSL,[ssl, http/1.1]}{127.0.0.1:40263} [junit4] 2> 75100 INFO (jetty-launcher-241-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2d2d0d96{/solr,null,AVAILABLE} [junit4] 2> 75100 INFO (jetty-launcher-241-thread-1) [ ] o.e.j.s.Server Started @77096ms [junit4] 2> 75100 INFO (jetty-launcher-241-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2a417328{/solr,null,AVAILABLE} [junit4] 2> 75100 INFO (jetty-launcher-241-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=40263} [junit4] 2> 75100 ERROR (jetty-launcher-241-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 75100 INFO (jetty-launcher-241-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0 [junit4] 2> 75100 INFO (jetty-launcher-241-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 75100 INFO (jetty-launcher-241-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 75100 INFO (jetty-launcher-241-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-06-19T12:29:59.502Z [junit4] 2> 75100 INFO (jetty-launcher-241-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2988dff8{SSL,[ssl, http/1.1]}{127.0.0.1:39239} [junit4] 2> 75100 INFO (jetty-launcher-241-thread-4) [ ] o.e.j.s.Server Started @77096ms [junit4] 2> 75100 INFO (jetty-launcher-241-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39239} [junit4] 2> 75101 ERROR (jetty-launcher-241-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 75101 INFO (jetty-launcher-241-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0 [junit4] 2> 75101 INFO (jetty-launcher-241-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 75101 INFO (jetty-launcher-241-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 75101 INFO (jetty-launcher-241-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-06-19T12:29:59.503Z [junit4] 2> 75107 INFO (jetty-launcher-241-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7222205{SSL,[ssl, http/1.1]}{127.0.0.1:43665} [junit4] 2> 75107 INFO (jetty-launcher-241-thread-2) [ ] o.e.j.s.Server Started @77102ms [junit4] 2> 75107 INFO (jetty-launcher-241-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43665} [junit4] 2> 75107 ERROR (jetty-launcher-241-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 75107 INFO (jetty-launcher-241-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0 [junit4] 2> 75107 INFO (jetty-launcher-241-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 75107 INFO (jetty-launcher-241-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 75107 INFO (jetty-launcher-241-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-06-19T12:29:59.509Z [junit4] 2> 75119 INFO (jetty-launcher-241-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 75123 INFO (jetty-launcher-241-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 75129 INFO (jetty-launcher-241-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 75130 INFO (jetty-launcher-241-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 75143 INFO (jetty-launcher-241-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41525/solr [junit4] 2> 75145 INFO (jetty-launcher-241-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41525/solr [junit4] 2> 75176 INFO (jetty-launcher-241-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41525/solr [junit4] 2> 75177 INFO (jetty-launcher-241-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41525/solr [junit4] 2> 75294 INFO (jetty-launcher-241-thread-1) [n:127.0.0.1:40263_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 75295 INFO (jetty-launcher-241-thread-3) [n:127.0.0.1:39523_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 75295 INFO (jetty-launcher-241-thread-1) [n:127.0.0.1:40263_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:40263_solr [junit4] 2> 75296 INFO (jetty-launcher-241-thread-3) [n:127.0.0.1:39523_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39523_solr [junit4] 2> 75297 INFO (jetty-launcher-241-thread-1) [n:127.0.0.1:40263_solr ] o.a.s.c.Overseer Overseer (id=98164762172194825-127.0.0.1:40263_solr-n_0000000000) starting [junit4] 2> 75316 INFO (jetty-launcher-241-thread-1) [n:127.0.0.1:40263_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40263_solr [junit4] 2> 75334 INFO (zkCallback-261-thread-1-processing-n:127.0.0.1:39523_solr) [n:127.0.0.1:39523_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 75334 INFO (zkCallback-260-thread-1-processing-n:127.0.0.1:40263_solr) [n:127.0.0.1:40263_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 75335 INFO (OverseerStateUpdate-98164762172194825-127.0.0.1:40263_solr-n_0000000000) [n:127.0.0.1:40263_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 75340 INFO (zkCallback-261-thread-2-processing-n:127.0.0.1:39523_solr) [n:127.0.0.1:39523_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 75343 INFO (jetty-launcher-241-thread-4) [n:127.0.0.1:39239_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 75344 INFO (jetty-launcher-241-thread-4) [n:127.0.0.1:39239_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 75346 INFO (jetty-launcher-241-thread-4) [n:127.0.0.1:39239_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39239_solr [junit4] 2> 75367 INFO (zkCallback-261-thread-2-processing-n:127.0.0.1:39523_solr) [n:127.0.0.1:39523_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 75367 INFO (zkCallback-260-thread-1-processing-n:127.0.0.1:40263_solr) [n:127.0.0.1:40263_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 75369 INFO (zkCallback-262-thread-1-processing-n:127.0.0.1:39239_solr) [n:127.0.0.1:39239_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 75370 INFO (jetty-launcher-241-thread-2) [n:127.0.0.1:43665_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3) [junit4] 2> 75372 INFO (jetty-launcher-241-thread-2) [n:127.0.0.1:43665_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 75374 INFO (jetty-launcher-241-thread-2) [n:127.0.0.1:43665_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43665_solr [junit4] 2> 75375 INFO (zkCallback-262-thread-1-processing-n:127.0.0.1:39239_solr) [n:127.0.0.1:39239_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 75375 INFO (zkCallback-261-thread-2-processing-n:127.0.0.1:39523_solr) [n:127.0.0.1:39523_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 75375 INFO (zkCallback-260-thread-1-processing-n:127.0.0.1:40263_solr) [n:127.0.0.1:40263_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 75377 INFO (zkCallback-263-thread-1-processing-n:127.0.0.1:43665_solr) [n:127.0.0.1:43665_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 75472 INFO (jetty-launcher-241-thread-4) [n:127.0.0.1:39239_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39239.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@45add891 [junit4] 2> 75480 INFO (jetty-launcher-241-thread-2) [n:127.0.0.1:43665_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43665.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@45add891 [junit4] 2> 75481 INFO (jetty-launcher-241-thread-4) [n:127.0.0.1:39239_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39239.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@45add891 [junit4] 2> 75481 INFO (jetty-launcher-241-thread-4) [n:127.0.0.1:39239_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39239.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@45add891 [junit4] 2> 75482 INFO (jetty-launcher-241-thread-4) [n:127.0.0.1:39239_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.io.stream.StreamExpressionTest_F2D6CCEA47D3CAF9-001/tempDir-001/node4/. [junit4] 2> 75483 INFO (jetty-launcher-241-thread-1) [n:127.0.0.1:40263_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40263.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@45add891 [junit4] 2> 75485 INFO (jetty-launcher-241-thread-2) [n:127.0.0.1:43665_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43665.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@45add891 [junit4] 2> 75486 INFO (jetty-launcher-241-thread-2) [n:127.0.0.1:43665_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43665.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@45add891 [junit4] 2> 75486 INFO (jetty-launcher-241-thread-1) [n:127.0.0.1:40263_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40263.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@45add891 [junit4] 2> 75486 INFO (jetty-launcher-241-thread-1) [n:127.0.0.1:40263_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40263.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@45add891 [junit4] 2> 75486 INFO (jetty-launcher-241-thread-2) [n:127.0.0.1:43665_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.io.stream.StreamExpressionTest_F2D6CCEA47D3CAF9-001/tempDir-001/node2/. [junit4] 2> 75487 INFO (jetty-launcher-241-thread-1) [n:127.0.0.1:40263_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.io.stream.StreamExpressionTest_F2D6CCEA47D3CAF9-001/tempDir-001/node1/. [junit4] 2> 75487 INFO (jetty-launcher-241-thread-3) [n:127.0.0.1:39523_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39523.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@45add891 [junit4] 2> 75490 INFO (jetty-launcher-241-thread-3) [n:127.0.0.1:39523_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39523.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@45add891 [junit4] 2> 75490 INFO (jetty-launcher-241-thread-3) [n:127.0.0.1:39523_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39523.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@45add891 [junit4] 2> 75491 INFO (jetty-launcher-241-thread-3) [n:127.0.0.1:39523_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.io.stream.StreamExpressionTest_F2D6CCEA47D3CAF9-001/tempDir-001/node3/. [junit4] 2> 75566 INFO (SUITE-StreamExpressionTest-seed#[F2D6CCEA47D3CAF9]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 75566 INFO (SUITE-StreamExpressionTest-seed#[F2D6CCEA47D3CAF9]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41525/solr ready [junit4] 2> 75598 INFO (qtp733897891-1588) [n:127.0.0.1:40263_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=collection1_collection&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 75602 INFO (OverseerThreadFactory-679-thread-1-processing-n:127.0.0.1:40263_solr) [n:127.0.0.1:40263_solr ] o.a.s.c.CreateCollectionCmd Create collection collection1_collection [junit4] 2> 75731 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=collection1_collection_shard2_replica_n1&action=CREATE&numShards=2&collection=collection1_collection&shard=shard2&wt=javabin&version=2&replicaType=NRT [junit4] 2> 75731 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 75749 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=collection1_collection_shard1_replica_n1&action=CREATE&numShards=2&collection=collection1_collection&shard=shard1&wt=javabin&version=2&replicaType=NRT [junit4] 2> 75749 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 75853 INFO (zkCallback-260-thread-1-processing-n:127.0.0.1:40263_solr) [n:127.0.0.1:40263_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1_collection/state.json] for collection [collection1_collection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 75853 INFO (zkCallback-262-thread-1-processing-n:127.0.0.1:39239_solr) [n:127.0.0.1:39239_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1_collection/state.json] for collection [collection1_collection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 76756 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 76763 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 76788 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.s.IndexSchema [collection1_collection_shard1_replica_n1] Schema name=test [junit4] 2> 76796 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.s.IndexSchema [collection1_collection_shard2_replica_n1] Schema name=test [junit4] 2> 76871 WARN (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.s.IndexSchema Field lowerfilt1and2 is not multivalued and destination for multiple copyFields (2) [junit4] 2> 76871 WARN (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.s.IndexSchema Field text is not multivalued and destination for multiple copyFields (3) [junit4] 2> 76872 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 76872 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'collection1_collection_shard2_replica_n1' using configuration from collection collection1_collection, trusted=true [junit4] 2> 76872 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40263.solr.core.collection1_collection.shard2.replica_n1' (registry 'solr.core.collection1_collection.shard2.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@45add891 [junit4] 2> 76872 WARN (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.s.IndexSchema Field lowerfilt1and2 is not multivalued and destination for multiple copyFields (2) [junit4] 2> 76872 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 76872 WARN (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.s.IndexSchema Field text is not multivalued and destination for multiple copyFields (3) [junit4] 2> 76872 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.c.SolrCore [[collection1_collection_shard2_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.io.stream.StreamExpressionTest_F2D6CCEA47D3CAF9-001/tempDir-001/node1/collection1_collection_shard2_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.io.stream.StreamExpressionTest_F2D6CCEA47D3CAF9-001/tempDir-001/node1/./collection1_collection_shard2_replica_n1/data/] [junit4] 2> 76873 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 76873 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'collection1_collection_shard1_replica_n1' using configuration from collection collection1_collection, trusted=true [junit4] 2> 76873 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39239.solr.core.collection1_collection.shard1.replica_n1' (registry 'solr.core.collection1_collection.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@45add891 [junit4] 2> 76873 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 76873 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.c.SolrCore [[collection1_collection_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.io.stream.StreamExpressionTest_F2D6CCEA47D3CAF9-001/tempDir-001/node4/collection1_collection_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.io.stream.StreamExpressionTest_F2D6CCEA47D3CAF9-001/tempDir-001/node4/./collection1_collection_shard1_replica_n1/data/] [junit4] 2> 76934 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 76934 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 76934 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 76935 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 76936 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 76936 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 76938 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@57225975[collection1_collection_shard1_replica_n1] main] [junit4] 2> 76939 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 76939 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 76940 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 76940 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 76940 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 76941 INFO (searcherExecutor-689-thread-1-processing-n:127.0.0.1:39239_solr x:collection1_collection_shard1_replica_n1 s:shard1 c:collection1_collection) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.c.SolrCore [collection1_collection_shard1_replica_n1] Registered new searcher Searcher@57225975[collection1_collection_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 76941 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1570636196838637568 [junit4] 2> 76942 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@191e5852[collection1_collection_shard2_replica_n1] main] [junit4] 2> 76943 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 76943 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 76944 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 76944 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1570636196841783296 [junit4] 2> 76945 INFO (searcherExecutor-688-thread-1-processing-n:127.0.0.1:40263_solr x:collection1_collection_shard2_replica_n1 s:shard2 c:collection1_collection) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.c.SolrCore [collection1_collection_shard2_replica_n1] Registered new searcher Searcher@191e5852[collection1_collection_shard2_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 76945 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 76945 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 76945 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:39239/solr/collection1_collection_shard1_replica_n1/ [junit4] 2> 76945 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 76946 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.c.SyncStrategy https://127.0.0.1:39239/solr/collection1_collection_shard1_replica_n1/ has no replicas [junit4] 2> 76946 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 76958 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:39239/solr/collection1_collection_shard1_replica_n1/ shard1 [junit4] 2> 76960 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 76960 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 76960 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:40263/solr/collection1_collection_shard2_replica_n1/ [junit4] 2> 76960 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 76960 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.c.SyncStrategy https://127.0.0.1:40263/solr/collection1_collection_shard2_replica_n1/ has no replicas [junit4] 2> 76960 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 76962 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:40263/solr/collection1_collection_shard2_replica_n1/ shard2 [junit4] 2> 77063 INFO (zkCallback-260-thread-1-processing-n:127.0.0.1:40263_solr) [n:127.0.0.1:40263_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1_collection/state.json] for collection [collection1_collection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 77063 INFO (zkCallback-262-thread-1-processing-n:127.0.0.1:39239_solr) [n:127.0.0.1:39239_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1_collection/state.json] for collection [collection1_collection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 77109 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 77111 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 x:collection1_collection_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=collection1_collection_shard1_replica_n1&action=CREATE&numShards=2&collection=collection1_collection&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1362 [junit4] 2> 77113 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 77114 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 x:collection1_collection_shard2_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=collection1_collection_shard2_replica_n1&action=CREATE&numShards=2&collection=collection1_collection&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1382 [junit4] 2> 77118 INFO (qtp733897891-1588) [n:127.0.0.1:40263_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas [junit4] 2> 77218 INFO (zkCallback-262-thread-1-processing-n:127.0.0.1:39239_solr) [n:127.0.0.1:39239_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1_collection/state.json] for collection [collection1_collection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 77219 INFO (zkCallback-260-thread-1-processing-n:127.0.0.1:40263_solr) [n:127.0.0.1:40263_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1_collection/state.json] for collection [collection1_collection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 77603 INFO (OverseerCollectionConfigSetProcessor-98164762172194825-127.0.0.1:40263_solr-n_0000000000) [n:127.0.0.1:40263_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 78119 INFO (qtp733897891-1588) [n:127.0.0.1:40263_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&name=collection1_collection&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=2520 [junit4] 2> 78119 INFO (SUITE-StreamExpressionTest-seed#[F2D6CCEA47D3CAF9]-worker) [ ] o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to finish - collection: collection1_collection failOnTimeout:true timeout (sec):90 [junit4] 2> 78119 INFO (SUITE-StreamExpressionTest-seed#[F2D6CCEA47D3CAF9]-worker) [ ] o.a.s.c.AbstractDistribZkTestBase Recoveries finished - collection: collection1_collection [junit4] 2> 78120 INFO (qtp733897891-1600) [n:127.0.0.1:40263_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :createalias with params collections=collection1_collection&name=collection1&action=CREATEALIAS&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 78223 INFO (qtp733897891-1600) [n:127.0.0.1:40263_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collections=collection1_collection&name=collection1&action=CREATEALIAS&wt=javabin&version=2} status=0 QTime=103 [junit4] 2> 78235 INFO (TEST-StreamExpressionTest.testRollupStream-seed#[F2D6CCEA47D3CAF9]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testRollupStream [junit4] 2> 78248 INFO (qtp204708024-1619) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:40263/solr/collection1_collection_shard2_replica_n1/&wt=javabin&version=2}{deleteByQuery=*:* (-1570636198202834944)} 0 5 [junit4] 2> 78249 INFO (qtp204708024-1615) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1570636198210174976,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 78249 INFO (qtp204708024-1615) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 78249 INFO (qtp204708024-1615) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 78249 INFO (qtp204708024-1615) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:40263/solr/collection1_collection_shard2_replica_n1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0 [junit4] 2> 78252 INFO (qtp733897891-1590) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1570636198212272128,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 78252 INFO (qtp733897891-1590) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 78252 INFO (qtp733897891-1590) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 78252 INFO (qtp733897891-1590) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard2_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:40263/solr/collection1_collection_shard2_replica_n1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 1 [junit4] 2> 78253 INFO (qtp733897891-1589) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard2_replica_n1] webapp=/solr path=/update params={_stateVer_=collection1_collection:3&commit=true&wt=javabin&version=2}{deleteByQuery=*:* (-1570636198199689216),commit=} 0 16 [junit4] 2> 78260 INFO (qtp204708024-1619) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=collection1_collection:3&wt=javabin&version=2}{add=[0 (1570636198218563584), 4 (1570636198220660736), 1 (1570636198221709312), 8 (1570636198221709313)]} 0 3 [junit4] 2> 78263 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard2_replica_n1] webapp=/solr path=/update params={_stateVer_=collection1_collection:3&wt=javabin&version=2}{add=[2 (1570636198217515008), 3 (1570636198220660736), 5 (1570636198221709312), 6 (1570636198221709313), 7 (1570636198224855040), 9 (1570636198224855041)]} 0 7 [junit4] 2> 78268 INFO (qtp733897891-1589) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1570636198230097920,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 78268 INFO (qtp204708024-1602) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1570636198230097920,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 78269 INFO (qtp733897891-1589) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@12609b8b commitCommandVersion:1570636198230097920 [junit4] 2> 78269 INFO (qtp204708024-1602) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@29147cb2 commitCommandVersion:1570636198230097920 [junit4] 2> 78287 INFO (qtp204708024-1602) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@467e42cc[collection1_collection_shard1_replica_n1] main] [junit4] 2> 78287 INFO (qtp733897891-1589) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@2d1761f3[collection1_collection_shard2_replica_n1] main] [junit4] 2> 78288 INFO (searcherExecutor-689-thread-1-processing-n:127.0.0.1:39239_solr x:collection1_collection_shard1_replica_n1 s:shard1 c:collection1_collection r:core_node2) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.c.SolrCore [collection1_collection_shard1_replica_n1] Registered new searcher Searcher@467e42cc[collection1_collection_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):c4)))} [junit4] 2> 78289 INFO (searcherExecutor-688-thread-1-processing-n:127.0.0.1:40263_solr x:collection1_collection_shard2_replica_n1 s:shard2 c:collection1_collection r:core_node1) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.c.SolrCore [collection1_collection_shard2_replica_n1] Registered new searcher Searcher@2d1761f3[collection1_collection_shard2_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):c6)))} [junit4] 2> 78289 INFO (qtp733897891-1589) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 78289 INFO (qtp204708024-1602) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 78289 INFO (qtp204708024-1602) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:39239/solr/collection1_collection_shard1_replica_n1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 20 [junit4] 2> 78289 INFO (qtp733897891-1589) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard2_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:39239/solr/collection1_collection_shard1_replica_n1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 20 [junit4] 2> 78289 INFO (qtp204708024-1615) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=collection1_collection:3&commit=true&wt=javabin&version=2}{commit=} 0 24 [junit4] 2> 78293 INFO (TEST-StreamExpressionTest.testRollupStream-seed#[F2D6CCEA47D3CAF9]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 78293 INFO (TEST-StreamExpressionTest.testRollupStream-seed#[F2D6CCEA47D3CAF9]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41525/solr ready [junit4] 2> 78297 INFO (qtp733897891-1591) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.c.S.Request [collection1_collection_shard2_replica_n1] webapp=/solr path=/select params={q=*:*&distrib=false&fl=a_s,a_i,a_f&sort=a_s+asc&wt=json&version=2.2} hits=6 status=0 QTime=0 [junit4] 2> 78297 INFO (qtp204708024-1599) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.c.S.Request [collection1_collection_shard1_replica_n1] webapp=/solr path=/select params={q=*:*&distrib=false&fl=a_s,a_i,a_f&sort=a_s+asc&wt=json&version=2.2} hits=4 status=0 QTime=0 [junit4] 2> 78303 INFO (TEST-StreamExpressionTest.testRollupStream-seed#[F2D6CCEA47D3CAF9]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testRollupStream [junit4] 2> 78318 INFO (TEST-StreamExpressionTest.testReverse-seed#[F2D6CCEA47D3CAF9]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testReverse [junit4] 2> 78325 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3da59693[collection1_collection_shard1_replica_n1] realtime] [junit4] 2> 78325 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6ca61a22[collection1_collection_shard2_replica_n1] realtime] [junit4] 2> 78325 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard2_replica_n1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:39239/solr/collection1_collection_shard1_replica_n1/&wt=javabin&version=2}{deleteByQuery=*:* (-1570636198287769600)} 0 2 [junit4] 2> 78327 INFO (qtp204708024-1619) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1570636198291963904,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 78327 INFO (qtp733897891-1591) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1570636198291963904,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 78327 INFO (qtp204708024-1619) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@29147cb2 commitCommandVersion:1570636198291963904 [junit4] 2> 78327 INFO (qtp733897891-1591) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@12609b8b commitCommandVersion:1570636198291963904 [junit4] 2> 78329 INFO (qtp733897891-1591) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@74d36813[collection1_collection_shard2_replica_n1] main] [junit4] 2> 78329 INFO (qtp204708024-1619) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@503bf6b7[collection1_collection_shard1_replica_n1] main] [junit4] 2> 78329 INFO (qtp733897891-1591) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 78329 INFO (qtp204708024-1619) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 78330 INFO (searcherExecutor-688-thread-1-processing-n:127.0.0.1:40263_solr x:collection1_collection_shard2_replica_n1 s:shard2 c:collection1_collection r:core_node1) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.c.SolrCore [collection1_collection_shard2_replica_n1] Registered new searcher Searcher@74d36813[collection1_collection_shard2_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 78330 INFO (qtp733897891-1591) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard2_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:39239/solr/collection1_collection_shard1_replica_n1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 3 [junit4] 2> 78330 INFO (searcherExecutor-689-thread-1-processing-n:127.0.0.1:39239_solr x:collection1_collection_shard1_replica_n1 s:shard1 c:collection1_collection r:core_node2) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.c.SolrCore [collection1_collection_shard1_replica_n1] Registered new searcher Searcher@503bf6b7[collection1_collection_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 78331 INFO (qtp204708024-1619) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:39239/solr/collection1_collection_shard1_replica_n1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 4 [junit4] 2> 78331 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=collection1_collection:3&commit=true&wt=javabin&version=2}{deleteByQuery=*:* (-1570636198283575296),commit=} 0 12 [junit4] 2> 78373 INFO (qtp733897891-1600) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard2_replica_n1] webapp=/solr path=/update params={_stateVer_=collection1_collection:3&wt=javabin&version=2}{add=[id_1 (1570636198298255360), id_3 (1570636198301401088), id_4 (1570636198301401089), id_5 (1570636198302449664), id_6 (1570636198302449665), id_7 (1570636198302449666), id_8 (1570636198302449667), id_9 (1570636198302449668), id_11 (1570636198303498240), id_12 (1570636198303498241), ... (125 adds)]} 0 39 [junit4] 2> 78386 INFO (qtp204708024-1615) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=collection1_collection:3&wt=javabin&version=2}{add=[id_2 (1570636198298255360), id_10 (1570636198301401088), id_13 (1570636198302449664), id_14 (1570636198302449665), id_16 (1570636198302449666), id_17 (1570636198302449667), id_18 (1570636198302449668), id_21 (1570636198302449669), id_22 (1570636198303498240), id_23 (1570636198303498241), ... (125 adds)]} 0 53 [junit4] 2> 78388 INFO (qtp204708024-1599) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1570636198355927040,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 78388 INFO (qtp733897891-1589) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1570636198355927040,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 78388 INFO (qtp733897891-1589) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@12609b8b commitCommandVersion:1570636198355927040 [junit4] 2> 78388 INFO (qtp204708024-1599) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@29147cb2 commitCommandVersion:1570636198355927040 [junit4] 2> 78417 INFO (qtp204708024-1599) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@19fbfdfd[collection1_collection_shard1_replica_n1] main] [junit4] 2> 78418 INFO (qtp204708024-1599) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 78419 INFO (searcherExecutor-689-thread-1-processing-n:127.0.0.1:39239_solr x:collection1_collection_shard1_replica_n1 s:shard1 c:collection1_collection r:core_node2) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.c.SolrCore [collection1_collection_shard1_replica_n1] Registered new searcher Searcher@19fbfdfd[collection1_collection_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(7.0.0):c125)))} [junit4] 2> 78419 INFO (qtp204708024-1599) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:39239/solr/collection1_collection_shard1_replica_n1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 31 [junit4] 2> 78419 INFO (qtp733897891-1589) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7835dc09[collection1_collection_shard2_replica_n1] main] [junit4] 2> 78421 INFO (searcherExecutor-688-thread-1-processing-n:127.0.0.1:40263_solr x:collection1_collection_shard2_replica_n1 s:shard2 c:collection1_collection r:core_node1) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.c.SolrCore [collection1_collection_shard2_replica_n1] Registered new searcher Searcher@7835dc09[collection1_collection_shard2_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(7.0.0):c125)))} [junit4] 2> 78421 INFO (qtp733897891-1589) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 78422 INFO (qtp733897891-1589) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard2_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:39239/solr/collection1_collection_shard1_replica_n1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 33 [junit4] 2> 78422 INFO (qtp204708024-1615) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=collection1_collection:3&commit=true&wt=javabin&version=2}{commit=} 0 34 [junit4] 2> 78443 INFO (qtp1064143424-1594) [n:127.0.0.1:43665_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 78448 INFO (qtp204708024-1615) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.c.S.Request [collection1_collection_shard1_replica_n1] webapp=/solr path=/stream params={expr=let(a%3Dtimeseries(collection1,+q%3D"*:*",+start%3D"2013-01-01T01:00:00.000Z",+end%3D"2016-12-01T01:00:00.000Z",+gap%3D"%2B1YEAR",+field%3D"test_dt",+count(*),+sum(price_f),+max(price_f),+min(price_f)),+c%3Dcol(a,+max(price_f)),+tuple(reverse%3Drev(c)))&wt=json&version=2.2} status=0 QTime=1 [junit4] 2> 78450 INFO (qtp204708024-1615) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 78451 INFO (qtp204708024-1615) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41525/solr ready [junit4] 2> 78486 INFO (qtp204708024-1599) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.c.S.Request [collection1_collection_shard1_replica_n1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=collection1_collection:3&_facet_={}&fl=id&fl=score&shards.purpose=1048580&start=0&fsv=true&collection=collection1_collection&shard.url=https://127.0.0.1:39239/solr/collection1_collection_shard1_replica_n1/&rows=0&version=2&q=*:*&json.facet={"timeseries":{"type":"range","field":"test_dt","start":"2013-01-01T01:00:00.000Z","end":"2016-12-01T01:00:00.000Z","gap":"%2B1YEAR","facet":{"facet_0":"sum(price_f)","facet_1":"max(price_f)","facet_2":"min(price_f)"}}}&field=test_dt&NOW=1497875402854&isShard=true&wt=javabin} hits=125 status=0 QTime=19 [junit4] 2> 78490 INFO (qtp733897891-1600) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.c.S.Request [collection1_collection_shard2_replica_n1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=collection1_collection:3&_facet_={}&fl=id&fl=score&shards.purpose=1048580&start=0&fsv=true&collection=collection1_collection&shard.url=https://127.0.0.1:40263/solr/collection1_collection_shard2_replica_n1/&rows=0&version=2&q=*:*&json.facet={"timeseries":{"type":"range","field":"test_dt","start":"2013-01-01T01:00:00.000Z","end":"2016-12-01T01:00:00.000Z","gap":"%2B1YEAR","facet":{"facet_0":"sum(price_f)","facet_1":"max(price_f)","facet_2":"min(price_f)"}}}&field=test_dt&NOW=1497875402854&isShard=true&wt=javabin} hits=125 status=0 QTime=23 [junit4] 2> 78495 INFO (qtp204708024-1602) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.c.S.Request [collection1_collection_shard1_replica_n1] webapp=/solr path=/select params={q=*:*&json.facet={"timeseries":{"type":"range","field":"test_dt","start":"2013-01-01T01:00:00.000Z","end":"2016-12-01T01:00:00.000Z","gap":"%2B1YEAR","facet":{"facet_0":"sum(price_f)","facet_1":"max(price_f)","facet_2":"min(price_f)"}}}&_stateVer_=collection1_collection:3&field=test_dt&rows=0&wt=javabin&version=2} hits=250 status=0 QTime=42 [junit4] 2> 78498 INFO (TEST-StreamExpressionTest.testReverse-seed#[F2D6CCEA47D3CAF9]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testReverse [junit4] 2> 78530 INFO (TEST-StreamExpressionTest.testPercentile-seed#[F2D6CCEA47D3CAF9]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testPercentile [junit4] 2> 78534 INFO (qtp733897891-1601) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@62cdc3b3[collection1_collection_shard2_replica_n1] realtime] [junit4] 2> 78534 INFO (qtp204708024-1610) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6b7c4d0f[collection1_collection_shard1_replica_n1] realtime] [junit4] 2> 78537 INFO (qtp204708024-1610) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:40263/solr/collection1_collection_shard2_replica_n1/&wt=javabin&version=2}{deleteByQuery=*:* (-1570636198507970560)} 0 4 [junit4] 2> 78540 INFO (qtp733897891-1588) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1570636198515310592,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 78540 INFO (qtp733897891-1588) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@12609b8b commitCommandVersion:1570636198515310592 [junit4] 2> 78540 INFO (qtp204708024-1599) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1570636198515310592,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 78540 INFO (qtp204708024-1599) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@29147cb2 commitCommandVersion:1570636198515310592 [junit4] 2> 78541 INFO (qtp733897891-1588) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@57134a03[collection1_collection_shard2_replica_n1] main] [junit4] 2> 78542 INFO (qtp733897891-1588) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 78543 INFO (searcherExecutor-688-thread-1-processing-n:127.0.0.1:40263_solr x:collection1_collection_shard2_replica_n1 s:shard2 c:collection1_collection r:core_node1) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.c.SolrCore [collection1_collection_shard2_replica_n1] Registered new searcher Searcher@57134a03[collection1_collection_shard2_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 78543 INFO (qtp733897891-1588) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard2_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:40263/solr/collection1_collection_shard2_replica_n1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 3 [junit4] 2> 78544 INFO (qtp204708024-1599) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5ddd924a[collection1_collection_shard1_replica_n1] main] [junit4] 2> 78545 INFO (qtp204708024-1599) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 78545 INFO (searcherExecutor-689-thread-1-processing-n:127.0.0.1:39239_solr x:collection1_collection_shard1_replica_n1 s:shard1 c:collection1_collection r:core_node2) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.c.SolrCore [collection1_collection_shard1_replica_n1] Registered new searcher Searcher@5ddd924a[collection1_collection_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 78546 INFO (qtp204708024-1599) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:40263/solr/collection1_collection_shard2_replica_n1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 6 [junit4] 2> 78546 INFO (qtp733897891-1601) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard2_replica_n1] webapp=/solr path=/update params={_stateVer_=collection1_collection:3&commit=true&wt=javabin&version=2}{deleteByQuery=*:* (-1570636198505873408),commit=} 0 15 [junit4] 2> 78552 INFO (qtp733897891-1588) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.c.S.Request [collection1_collection_shard2_replica_n1] webapp=/solr path=/stream params={expr=percentile(array(1,2,3,4,5,6,7,8,9,10,11),+50)&wt=json&version=2.2} status=0 QTime=0 [junit4] 2> 78583 INFO (qtp733897891-1601) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.c.S.Request [collection1_collection_shard2_replica_n1] webapp=/solr path=/stream params={expr=percentile(array(11,10,3,4,5,6,7,8,9,2,1),+50)&wt=json&version=2.2} status=0 QTime=0 [junit4] 2> 78587 INFO (qtp733897891-1590) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.c.S.Request [collection1_collection_shard2_replica_n1] webapp=/solr path=/stream params={expr=percentile(array(11,10,3,4,5,6,7,8,9,2,1),+20)&wt=json&version=2.2} status=0 QTime=0 [junit4] 2> 78587 INFO (TEST-StreamExpressionTest.testPercentile-seed#[F2D6CCEA47D3CAF9]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testPercentile [junit4] 2> 78605 INFO (TEST-StreamExpressionTest.testDescribe-seed#[F2D6CCEA47D3CAF9]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDescribe [junit4] 2> 78608 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard2_replica_n1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:39239/solr/collection1_collection_shard1_replica_n1/&wt=javabin&version=2}{deleteByQuery=*:* (-1570636198585565184)} 0 0 [junit4] 2> 78609 INFO (qtp204708024-1619) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1570636198587662336,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 78609 INFO (qtp204708024-1619) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 78609 INFO (qtp204708024-1619) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 78609 INFO (qtp204708024-1619) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:39239/solr/collection1_collection_shard1_replica_n1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0 [junit4] 2> 78610 INFO (qtp733897891-1588) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1570636198588710912,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 78610 INFO (qtp733897891-1588) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 78610 INFO (qtp733897891-1588) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 78610 INFO (qtp733897891-1588) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard2_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:39239/solr/collection1_collection_shard1_replica_n1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0 [junit4] 2> 78610 INFO (qtp204708024-1597) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=collection1_collection:3&commit=true&wt=javabin&version=2}{deleteByQuery=*:* (-1570636198584516608),commit=} 0 4 [junit4] 2> 78614 INFO (qtp204708024-1615) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=collection1_collection:3&wt=javabin&version=2}{add=[1 (1570636198590808064), 4 (1570636198592905216)]} 0 2 [junit4] 2> 78614 INFO (qtp733897891-1591) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard2_replica_n1] webapp=/solr path=/update params={_stateVer_=collection1_collection:3&wt=javabin&version=2}{add=[2 (1570636198590808064), 3 (1570636198592905216), 5 (1570636198592905217), 6 (1570636198592905218), 7 (1570636198592905219)]} 0 2 [junit4] 2> 78616 INFO (qtp204708024-1602) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1570636198595002368,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 78616 INFO (qtp204708024-1602) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@29147cb2 commitCommandVersion:1570636198595002368 [junit4] 2> 78617 INFO (qtp733897891-1600) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1570636198596050944,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 78617 INFO (qtp733897891-1600) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@12609b8b commitCommandVersion:1570636198596050944 [junit4] 2> 78624 INFO (qtp204708024-1602) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6272fb78[collection1_collection_shard1_replica_n1] main] [junit4] 2> 78625 INFO (searcherExecutor-689-thread-1-processing-n:127.0.0.1:39239_solr x:collection1_collection_shard1_replica_n1 s:shard1 c:collection1_collection r:core_node2) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.c.SolrCore [collection1_collection_shard1_replica_n1] Registered new searcher Searcher@6272fb78[collection1_collection_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(7.0.0):c2)))} [junit4] 2> 78625 INFO (qtp204708024-1602) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 78625 INFO (qtp204708024-1602) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:40263/solr/collection1_collection_shard2_replica_n1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 9 [junit4] 2> 78629 INFO (qtp733897891-1600) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@26bd0d1c[collection1_collection_shard2_replica_n1] main] [junit4] 2> 78631 INFO (searcherExecutor-688-thread-1-processing-n:127.0.0.1:40263_solr x:collection1_collection_shard2_replica_n1 s:shard2 c:collection1_collection r:core_node1) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.c.SolrCore [collection1_collection_shard2_replica_n1] Registered new searcher Searcher@26bd0d1c[collection1_collection_shard2_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(7.0.0):c5)))} [junit4] 2> 78631 INFO (qtp733897891-1600) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 78631 INFO (qtp733897891-1600) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard2_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:40263/solr/collection1_collection_shard2_replica_n1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 14 [junit4] 2> 78631 INFO (qtp733897891-1590) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard2_replica_n1] webapp=/solr path=/update params={_stateVer_=collection1_collection:3&commit=true&wt=javabin&version=2}{commit=} 0 16 [junit4] 2> 78636 INFO (qtp733897891-1588) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.c.S.Request [collection1_collection_shard2_replica_n1] webapp=/solr path=/stream params={expr=let(a%3Dsearch(collection1,+q%3D"col_s:a",+fl%3D"price_f,+order_i",+sort%3D"order_i+asc"),+b%3Dcol(a,+price_f),++tuple(stats%3Ddescribe(b)))&wt=json&version=2.2} status=0 QTime=0 [junit4] 2> 78642 INFO (qtp733897891-1601) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.c.S.Request [collection1_collection_shard2_replica_n1] webapp=/solr path=/select params={q=col_s:a&distrib=false&fl=price_f,+order_i&sort=order_i+asc&wt=json&version=2.2} hits=5 status=0 QTime=0 [junit4] 2> 78645 INFO (qtp204708024-1615) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.c.S.Request [collection1_collection_shard1_replica_n1] webapp=/solr path=/select params={q=col_s:a&distrib=false&fl=price_f,+order_i&sort=order_i+asc&wt=json&version=2.2} hits=2 status=0 QTime=0 [junit4] 2> 78669 INFO (TEST-StreamExpressionTest.testDescribe-seed#[F2D6CCEA47D3CAF9]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDescribe [junit4] 2> 78686 INFO (TEST-StreamExpressionTest.testClassifyStream-seed#[F2D6CCEA47D3CAF9]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testClassifyStream [junit4] 2> 78688 INFO (qtp204708024-1599) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6ebbb85f[collection1_collection_shard1_replica_n1] realtime] [junit4] 2> 78688 INFO (qtp733897891-1604) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@549f0dc2[collection1_collection_shard2_replica_n1] realtime] [junit4] 2> 78688 INFO (qtp204708024-1599) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_collection_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:40263/solr/collection1_collection_shard2_replica_n1/&wt=javabin&version=2}{deleteByQuery=*:* (-1570636198669451264)} 0 1 [junit4] 2> 78689 INFO (qtp204708024-1615) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1570636198671548416,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 78689 INFO (qtp733897891-1591) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1570636198671548416,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 78689 INFO (qtp204708024-1615) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@29147cb2 commitCommandVersion:1570636198671548416 [junit4] 2> 78689 INFO (qtp733897891-1591) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@12609b8b commitCommandVersion:1570636198671548416 [junit4] 2> 78691 INFO (qtp733897891-1591) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@ec99000[collection1_collection_shard2_replica_n1] main] [junit4] 2> 78691 INFO (qtp204708024-1615) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4f1c97a3[collection1_collection_shard1_replica_n1] main] [junit4] 2> 78691 INFO (qtp204708024-1615) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 78691 INFO (qtp733897891-1591) [n:127.0.0.1:40263_solr c:co [...truncated too long message...] -242-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 144940 INFO (jetty-closer-242-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 144940 INFO (jetty-closer-242-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 144941 INFO (jetty-closer-242-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 144941 INFO (jetty-closer-242-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 144941 INFO (jetty-closer-242-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 144941 INFO (zkCallback-263-thread-1-processing-n:127.0.0.1:43665_solr) [n:127.0.0.1:43665_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 144941 INFO (zkCallback-260-thread-2-processing-n:127.0.0.1:40263_solr) [n:127.0.0.1:40263_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 144942 INFO (zkCallback-262-thread-1-processing-n:127.0.0.1:39239_solr) [n:127.0.0.1:39239_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 144942 INFO (zkCallback-1711-thread-1-processing-n:127.0.0.1:40263_solr x:collection1_collection_shard2_replica_n1 s:shard2 c:collection1_collection r:core_node1) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 144942 INFO (jetty-closer-242-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 144942 INFO (jetty-closer-242-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 144942 INFO (jetty-closer-242-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 144943 INFO (coreCloseExecutor-820-thread-1) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.c.SolrCore [collection1_collection_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@73236bdf [junit4] 2> 144943 WARN (zkCallback-263-thread-1-processing-n:127.0.0.1:43665_solr) [n:127.0.0.1:43665_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 144943 INFO (coreCloseExecutor-821-thread-1) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.c.SolrCore [collection1_collection_shard2_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@6ba7718b [junit4] 2> 144944 INFO (jetty-closer-242-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2d2d0d96{/solr,null,UNAVAILABLE} [junit4] 2> 144944 INFO (zkCallback-1711-thread-1-processing-n:127.0.0.1:40263_solr x:collection1_collection_shard2_replica_n1 s:shard2 c:collection1_collection r:core_node1) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 144944 INFO (coreCloseExecutor-820-thread-1) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1_collection.shard1.replica_n1, tag=1931701215 [junit4] 2> 144944 INFO (zkCallback-262-thread-2-processing-n:127.0.0.1:39239_solr) [n:127.0.0.1:39239_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 144944 INFO (zkCallback-260-thread-2-processing-n:127.0.0.1:40263_solr) [n:127.0.0.1:40263_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 144944 INFO (coreCloseExecutor-821-thread-1) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1_collection.shard2.replica_n1, tag=1806135691 [junit4] 2> 144946 INFO (coreCloseExecutor-820-thread-1) [n:127.0.0.1:39239_solr c:collection1_collection s:shard1 r:core_node2 x:collection1_collection_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.collection1_collection.shard1.leader, tag=1931701215 [junit4] 2> 144946 INFO (coreCloseExecutor-821-thread-1) [n:127.0.0.1:40263_solr c:collection1_collection s:shard2 r:core_node1 x:collection1_collection_shard2_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.collection1_collection.shard2.leader, tag=1806135691 [junit4] 2> 144947 WARN (zkCallback-262-thread-2-processing-n:127.0.0.1:39239_solr) [n:127.0.0.1:39239_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 144948 INFO (jetty-closer-242-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2a417328{/solr,null,UNAVAILABLE} [junit4] 2> 144948 INFO (zkCallback-260-thread-2-processing-n:127.0.0.1:40263_solr) [n:127.0.0.1:40263_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1) [junit4] 2> 144949 INFO (jetty-closer-242-thread-4) [ ] o.a.s.c.Overseer Overseer (id=98164762172194825-127.0.0.1:40263_solr-n_0000000000) closing [junit4] 2> 144949 INFO (OverseerStateUpdate-98164762172194825-127.0.0.1:40263_solr-n_0000000000) [n:127.0.0.1:40263_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:40263_solr [junit4] 2> 144949 WARN (zkCallback-260-thread-2-processing-n:127.0.0.1:40263_solr) [n:127.0.0.1:40263_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 144949 INFO (jetty-closer-242-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7f9741a8{/solr,null,UNAVAILABLE} [junit4] 2> 146441 WARN (zkCallback-261-thread-2-processing-n:127.0.0.1:39523_solr) [n:127.0.0.1:39523_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 146442 INFO (jetty-closer-242-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7ab783a2{/solr,null,UNAVAILABLE} [junit4] 2> 146442 ERROR (SUITE-StreamExpressionTest-seed#[F2D6CCEA47D3CAF9]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes [junit4] 2> 146442 INFO (SUITE-StreamExpressionTest-seed#[F2D6CCEA47D3CAF9]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:41525 41525 [junit4] 2> 148019 INFO (Thread-476) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:41525 41525 [junit4] 2> 148020 WARN (Thread-476) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 70 /solr/aliases.json [junit4] 2> 11 /solr/configs/conf [junit4] 2> 4 /solr/security.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 70 /solr/clusterprops.json [junit4] 2> 70 /solr/clusterstate.json [junit4] 2> 4 /solr/collections/destination/state.json [junit4] 2> 4 /solr/collections/parallelDestinationCollection/state.json [junit4] 2> 4 /solr/collections/destinationCollection/state.json [junit4] 2> 4 /solr/collections/mainCorpus/state.json [junit4] 2> 3 /solr/collections/workQueue/state.json [junit4] 2> 2 /solr/overseer_elect/election/98164762172194825-127.0.0.1:40263_solr-n_0000000000 [junit4] 2> 2 /solr/collections/collection1_collection/state.json [junit4] 2> 2 /solr/collections/parallelDestinationCollection1/state.json [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 70 /solr/live_nodes [junit4] 2> 70 /solr/collections [junit4] 2> [junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.io.stream.StreamExpressionTest_F2D6CCEA47D3CAF9-001 [junit4] 2> NOTE: test params are: codec=SimpleText, sim=RandomSimilarity(queryNorm=true): {}, locale=pl-PL, timezone=America/Ojinaga [junit4] 2> NOTE: Linux 4.10.0-21-generic amd64/Oracle Corporation 1.8.0_131 (64-bit)/cpus=8,threads=1,free=94935416,total=521666560 [junit4] 2> NOTE: All tests run in this JVM: [FieldAnalysisResponseTest, StreamExpressionToExplanationTest, CommonParamsTest, LargeVolumeEmbeddedTest, CeilingEvaluatorTest, TestJsonRecordReader, HttpSolrClientBuilderTest, DivideEvaluatorTest, AddEvaluatorTest, TestConfigSetAdminRequest, SolrExampleStreamingTest, SelectWithEvaluatorsTest, CloudSolrClientBuilderTest, StreamExpressionParserTest, CloudSolrClientTest, TangentEvaluatorTest, SchemaTest, PowerEvaluatorTest, TestXMLEscaping, JdbcDriverTest, TestSpellCheckResponse, ArcSineEvaluatorTest, GraphTest, StreamExpressionTest] [junit4] Completed [135/135 (1!)] on J0 in 73.08s, 89 tests, 1 error, 9 skipped <<< FAILURES! [...truncated 42415 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
