You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2017/12/27 09:29:47 UTC
[JENKINS] Lucene-Solr-7.x-Solaris (64bit/jdk1.8.0) - Build # 355 -
Still Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Solaris/355/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseSerialGC
2 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.AutoAddReplicasPlanActionTest.testSimple
Error Message:
No live SolrServers available to handle this request:[http://127.0.0.1:50655/solr]
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:50655/solr]
at __randomizedtesting.SeedInfo.seed([97917F4C9451E67B:AF225BB2B3A232AA]:0)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:462)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1104)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:884)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:817)
at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219)
at org.apache.solr.cloud.autoscaling.AutoAddReplicasPlanActionTest.testSimple(AutoAddReplicasPlanActionTest.java:110)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Caused by: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:50655/solr
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:657)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:413)
... 44 more
Caused by: java.net.SocketException: Connection reset
at java.net.SocketInputStream.read(SocketInputStream.java:210)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153)
at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:282)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:165)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:542)
... 48 more
FAILED: org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigReplication
Error Message:
Index: 0, Size: 0
Stack Trace:
java.lang.IndexOutOfBoundsException: Index: 0, Size: 0
at __randomizedtesting.SeedInfo.seed([97917F4C9451E67B:83D92419B7565B65]:0)
at java.util.ArrayList.rangeCheck(ArrayList.java:657)
at java.util.ArrayList.get(ArrayList.java:433)
at org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigReplication(TestReplicationHandler.java:561)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 11811 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/init-core-data-001
[junit4] 2> 322742 WARN (SUITE-TestReplicationHandler-seed#[97917F4C9451E67B]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=8 numCloses=8
[junit4] 2> 322742 INFO (SUITE-TestReplicationHandler-seed#[97917F4C9451E67B]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 322742 INFO (SUITE-TestReplicationHandler-seed#[97917F4C9451E67B]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=None)
[junit4] 2> 322742 INFO (SUITE-TestReplicationHandler-seed#[97917F4C9451E67B]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 322751 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.SolrTestCaseJ4 ###Starting doTestReplicateAfterStartup
[junit4] 2> 322752 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-001/collection1
[junit4] 2> 322757 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 322758 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2518fdb0{/solr,null,AVAILABLE}
[junit4] 2> 322761 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@52a19505{HTTP/1.1,[http/1.1]}{127.0.0.1:58971}
[junit4] 2> 322761 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.e.j.s.Server Started @325788ms
[junit4] 2> 322761 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=58971}
[junit4] 2> 322762 ERROR (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 322762 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.3.0
[junit4] 2> 322762 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 322762 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 322762 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-12-27T07:57:59.184Z
[junit4] 2> 322762 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-001/solr.xml
[junit4] 2> 322776 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 322776 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 322777 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@5fdaeeaf, but no JMX reporters were configured - adding default JMX reporter.
[junit4] 2> 322821 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fdaeeaf
[junit4] 2> 322834 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fdaeeaf
[junit4] 2> 322839 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fdaeeaf
[junit4] 2> 322842 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-001/.
[junit4] 2> 322842 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 322845 INFO (coreLoadExecutor-985-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 322861 INFO (coreLoadExecutor-985-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0
[junit4] 2> 322881 INFO (coreLoadExecutor-985-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 322884 INFO (coreLoadExecutor-985-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 322884 INFO (coreLoadExecutor-985-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-001/./collection1, trusted=true
[junit4] 2> 322884 INFO (coreLoadExecutor-985-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fdaeeaf
[junit4] 2> 322884 INFO (coreLoadExecutor-985-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 322884 INFO (coreLoadExecutor-985-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-001/collection1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-001/./collection1/data/]
[junit4] 2> 322886 INFO (coreLoadExecutor-985-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=37, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 322950 INFO (coreLoadExecutor-985-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 322950 INFO (coreLoadExecutor-985-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 322951 INFO (coreLoadExecutor-985-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=12, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=27.4736328125, floorSegmentMB=1.6328125, forceMergeDeletesPctAllowed=23.282325756198887, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6910596725294958
[junit4] 2> 322951 INFO (coreLoadExecutor-985-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@107d0d87[collection1] main]
[junit4] 2> 322952 INFO (coreLoadExecutor-985-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-001/collection1/conf
[junit4] 2> 322952 INFO (coreLoadExecutor-985-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 322953 INFO (coreLoadExecutor-985-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 322954 INFO (searcherExecutor-986-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@107d0d87[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 323458 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-002/collection1
[junit4] 2> 323461 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 323463 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4c969422{/solr,null,AVAILABLE}
[junit4] 2> 323464 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@44a07ccd{HTTP/1.1,[http/1.1]}{127.0.0.1:37893}
[junit4] 2> 323464 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.e.j.s.Server Started @326491ms
[junit4] 2> 323464 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-002/collection1/data, hostContext=/solr, hostPort=37893}
[junit4] 2> 323464 ERROR (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 323464 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.3.0
[junit4] 2> 323464 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 323464 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 323464 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-12-27T07:57:59.886Z
[junit4] 2> 323464 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-002/solr.xml
[junit4] 2> 323497 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 323497 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 323498 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@5fdaeeaf, but no JMX reporters were configured - adding default JMX reporter.
[junit4] 2> 323547 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fdaeeaf
[junit4] 2> 323558 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fdaeeaf
[junit4] 2> 323558 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fdaeeaf
[junit4] 2> 323560 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-002/.
[junit4] 2> 323560 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 323562 INFO (coreLoadExecutor-995-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 323584 INFO (coreLoadExecutor-995-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0
[junit4] 2> 323591 INFO (coreLoadExecutor-995-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 323593 INFO (coreLoadExecutor-995-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 323593 INFO (coreLoadExecutor-995-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-002/./collection1, trusted=true
[junit4] 2> 323593 INFO (coreLoadExecutor-995-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fdaeeaf
[junit4] 2> 323594 INFO (coreLoadExecutor-995-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 323594 INFO (coreLoadExecutor-995-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-002/collection1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-002/./collection1/data/]
[junit4] 2> 323594 INFO (coreLoadExecutor-995-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=37, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 323672 INFO (coreLoadExecutor-995-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 323672 INFO (coreLoadExecutor-995-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 323687 INFO (coreLoadExecutor-995-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=12, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=27.4736328125, floorSegmentMB=1.6328125, forceMergeDeletesPctAllowed=23.282325756198887, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6910596725294958
[junit4] 2> 323688 INFO (coreLoadExecutor-995-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@12be64f9[collection1] main]
[junit4] 2> 323691 INFO (coreLoadExecutor-995-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-002/collection1/conf
[junit4] 2> 323706 INFO (coreLoadExecutor-995-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms
[junit4] 2> 323706 INFO (coreLoadExecutor-995-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 323709 INFO (searcherExecutor-996-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@12be64f9[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 323710 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@44a07ccd{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 323711 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=138734208
[junit4] 2> 323711 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 323711 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2458ac12: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@789129b6
[junit4] 2> 323717 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 323717 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2651be14: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@3a57ebc
[junit4] 2> 323722 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 323723 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7fae3ca4: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@79aea10
[junit4] 2> 323724 INFO (coreCloseExecutor-1001-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@3567a569
[junit4] 2> 323724 INFO (coreCloseExecutor-1001-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=895985001
[junit4] 2> 323725 INFO (coreCloseExecutor-1001-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@25998b72: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@540fe531
[junit4] 2> 323736 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4c969422{/solr,null,UNAVAILABLE}
[junit4] 2> 323743 INFO (qtp1649333230-2662) [ x:collection1] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 323746 INFO (qtp1649333230-2662) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:*} 0 2
[junit4] 2> 323747 INFO (qtp1649333230-2660) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 323747 INFO (qtp1649333230-2660) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@33e4d232 commitCommandVersion:0
[junit4] 2> 323749 INFO (qtp1649333230-2660) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7c1e2005[collection1] main]
[junit4] 2> 323749 INFO (qtp1649333230-2660) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 323752 INFO (searcherExecutor-986-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@7c1e2005[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 323752 INFO (qtp1649333230-2660) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 4
[junit4] 2> 323755 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@52a19505{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 323755 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1370349047
[junit4] 2> 323756 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 323756 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6248e267: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@3fbd2c7f
[junit4] 2> 323757 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 323757 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@50b8c444: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@3a57ebc
[junit4] 2> 323757 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 323757 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7a5a0a6f: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@79aea10
[junit4] 2> 323760 INFO (coreCloseExecutor-1003-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@18a426ae
[junit4] 2> 323760 INFO (coreCloseExecutor-1003-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=413410990
[junit4] 2> 323760 INFO (coreCloseExecutor-1003-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@399b830c: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@11bbf0a1
[junit4] 2> 323767 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2518fdb0{/solr,null,UNAVAILABLE}
[junit4] 2> 323774 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 323777 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6c7fee61{/solr,null,AVAILABLE}
[junit4] 2> 323780 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4e1a9184{HTTP/1.1,[http/1.1]}{127.0.0.1:55566}
[junit4] 2> 323780 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.e.j.s.Server Started @326807ms
[junit4] 2> 323781 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=55566}
[junit4] 2> 323786 ERROR (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 323786 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.3.0
[junit4] 2> 323786 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 323786 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 323786 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-12-27T07:58:00.208Z
[junit4] 2> 323787 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-001/solr.xml
[junit4] 2> 323790 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 323790 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 323791 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@5fdaeeaf, but no JMX reporters were configured - adding default JMX reporter.
[junit4] 2> 323830 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fdaeeaf
[junit4] 2> 323839 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fdaeeaf
[junit4] 2> 323839 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fdaeeaf
[junit4] 2> 323842 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-001/.
[junit4] 2> 323842 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[97917F4C9451E67B]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 323858 INFO (coreLoadExecutor-1010-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 323887 INFO (coreLoadExecutor-1010-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0
[junit4] 2> 323894 INFO (coreLoadExecutor-1010-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 323896 INFO (coreLoadExecutor-1010-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 323896 INFO (coreLoadExecutor-1010-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-001/./collection1, trusted=true
[junit4] 2> 323896 INFO (coreLoadExecutor-1010-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fdaeeaf
[junit4] 2> 323896 INFO (coreLoadExecutor-1010-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 323896 INFO (coreLoadExecutor-1010-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-001/collection1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-001/./collection1/data/]
[junit4] 2> 323898 INFO (coreLoadExecutor-1010-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=37, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 323949 INFO (coreLoadExecutor-1010-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 323949 INFO (coreLoadExecutor-1010-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 323950 INFO (coreLoadExecutor-1010-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=12, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=27.4736328125, floorSegmentMB=1.6328125, forceMergeDeletesPctAllowed=23.282325756198887, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6910596725294958
[junit4] 2> 323951 INFO (coreLoadExecutor-1010-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@339770ec[collection1] main]
[junit4] 2> 323951 INFO (coreLoadExecutor-1010-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_97917F4C9451E67B-001/solr-instance-001/collection1/conf
[junit4] 2> 323953 INFO (coreLoadExecutor-1010-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml
[junit4] 2> 323953 INFO (coreLoadExecutor-1010-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 323954 INFO (searcherExecutor-1011-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@339770ec[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 323963 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[0]} 0 2
[junit4] 2> 323971 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1]} 0 5
[junit4] 2> 323973 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2]} 0 0
[junit4] 2> 323974 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[3]} 0 0
[junit4] 2> 323976 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[4]} 0 0
[junit4] 2> 323977 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[5]} 0 0
[junit4] 2> 323978 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[6]} 0 0
[junit4] 2> 323979 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[7]} 0 0
[junit4] 2> 323980 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[8]} 0 0
[junit4] 2> 323981 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[9]} 0 0
[junit4] 2> 323981 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[10]} 0 0
[junit4] 2> 323982 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[11]} 0 0
[junit4] 2> 323983 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[12]} 0 0
[junit4] 2> 323984 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[13]} 0 0
[junit4] 2> 323984 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[14]} 0 0
[junit4] 2> 323985 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[15]} 0 0
[junit4] 2> 323986 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[16]} 0 0
[junit4] 2> 323986 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[17]} 0 0
[junit4] 2> 323987 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[18]} 0 0
[junit4] 2> 323988 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[19]} 0 0
[junit4] 2> 323988 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[20]} 0 0
[junit4] 2> 323989 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[21]} 0 0
[junit4] 2> 323989 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[22]} 0 0
[junit4] 2> 323990 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[23]} 0 0
[junit4] 2> 323991 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[24]} 0 0
[junit4] 2> 323992 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[25]} 0 0
[junit4] 2> 323992 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[26]} 0 0
[junit4] 2> 323993 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[27]} 0 0
[junit4] 2> 323993 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[28]} 0 0
[junit4] 2> 323994 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[29]} 0 0
[junit4] 2> 323994 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[30]} 0 0
[junit4] 2> 323995 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[31]} 0 0
[junit4] 2> 323996 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[32]} 0 0
[junit4] 2> 323996 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[33]} 0 0
[junit4] 2> 323997 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[34]} 0 0
[junit4] 2> 323998 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[35]} 0 0
[junit4] 2> 323999 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[36]} 0 0
[junit4] 2> 324000 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[37]} 0 0
[junit4] 2> 324000 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[38]} 0 0
[junit4] 2> 324001 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[39]} 0 0
[junit4] 2> 324002 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[40]} 0 0
[junit4] 2> 324003 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[41]} 0 0
[junit4] 2> 324003 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[42]} 0 0
[junit4] 2> 324004 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[43]} 0 0
[junit4] 2> 324005 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[44]} 0 0
[junit4] 2> 324006 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[45]} 0 0
[junit4] 2> 324006 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[46]} 0 0
[junit4] 2> 324007 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[47]} 0 0
[junit4] 2> 324008 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[48]} 0 0
[junit4] 2> 324009 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[49]} 0 0
[junit4] 2> 324010 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[50]} 0 0
[junit4] 2> 324011 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[51]} 0 0
[junit4] 2> 324011 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[52]} 0 0
[junit4] 2> 324012 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[53]} 0 0
[junit4] 2> 324013 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[54]} 0 0
[junit4] 2> 324014 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[55]} 0 0
[junit4] 2> 324015 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[56]} 0 0
[junit4] 2> 324015 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[57]} 0 0
[junit4] 2> 324016 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[58]} 0 0
[junit4] 2> 324016 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[59]} 0 0
[junit4] 2> 324017 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[60]} 0 0
[junit4] 2> 324018 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[61]} 0 0
[junit4] 2> 324018 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[62]} 0 0
[junit4] 2> 324019 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[63]} 0 0
[junit4] 2> 324020 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[64]} 0 0
[junit4] 2> 324021 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[65]} 0 0
[junit4] 2> 324021 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[66]} 0 0
[junit4] 2> 324022 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[67]} 0 0
[junit4] 2> 324023 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[68]} 0 0
[junit4] 2> 324024 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[69]} 0 0
[junit4] 2> 324025 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[70]} 0 0
[junit4] 2> 324025 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[71]} 0 0
[junit4] 2> 324026 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[72]} 0 0
[junit4] 2> 324027 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[73]} 0 0
[junit4] 2> 324027 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[74]} 0 0
[junit4] 2> 324028 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[75]} 0 0
[junit4] 2> 324028 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[76]} 0 0
[junit4] 2> 324029 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[77]} 0 0
[junit4] 2> 324029 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[78]} 0 0
[junit4] 2> 324030 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[79]} 0 0
[junit4] 2> 324031 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[80]} 0 0
[junit4] 2> 324032 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[81]} 0 0
[junit4] 2> 324033 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[82]} 0 0
[junit4] 2> 324033 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[83]} 0 0
[junit4] 2> 324034 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[84]} 0 0
[junit4] 2> 324035 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[85]} 0 0
[junit4] 2> 324035 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[86]} 0 0
[junit4] 2> 324036 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[87]} 0 0
[junit4] 2> 324036 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[88]} 0 0
[junit4] 2> 324037 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[89]} 0 0
[junit4] 2> 324037 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[90]} 0 0
[junit4] 2> 324045 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[91]} 0 0
[junit4] 2> 324046 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[92]} 0 0
[junit4] 2> 324047 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[93]} 0 0
[junit4] 2> 324048 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[94]} 0 0
[junit4] 2> 324048 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[95]} 0 0
[junit4] 2> 324049 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[96]} 0 0
[junit4] 2> 324050 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[97]} 0 0
[junit4] 2> 324050 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[98]} 0 0
[junit4] 2> 324051 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[99]} 0 0
[junit4] 2> 324052 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[100]} 0 0
[junit4] 2> 324052 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[101]} 0 0
[junit4] 2> 324053 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[102]} 0 0
[junit4] 2> 324054 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[103]} 0 0
[junit4] 2> 324054 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[104]} 0 0
[junit4] 2> 324055 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[105]} 0 0
[junit4] 2> 324056 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[106]} 0 0
[junit4] 2> 324057 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[107]} 0 0
[junit4] 2> 324058 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[108]} 0 0
[junit4] 2> 324058 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[109]} 0 0
[junit4] 2> 324060 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[110]} 0 0
[junit4] 2> 324063 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[111]} 0 0
[junit4] 2> 324064 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[112]} 0 0
[junit4] 2> 324064 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[113]} 0 0
[junit4] 2> 324065 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[114]} 0 0
[junit4] 2> 324066 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[115]} 0 0
[junit4] 2> 324067 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[116]} 0 0
[junit4] 2> 324067 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[117]} 0 0
[junit4] 2> 324068 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[118]} 0 0
[junit4] 2> 324069 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[119]} 0 0
[junit4] 2> 324070 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[120]} 0 0
[junit4] 2> 324071 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[121]} 0 0
[junit4] 2> 324072 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[122]} 0 0
[junit4] 2> 324075 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[123]} 0 0
[junit4] 2> 324076 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[124]} 0 0
[junit4] 2> 324077 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[125]} 0 0
[junit4] 2> 324077 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[126]} 0 0
[junit4] 2> 324078 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[127]} 0 0
[junit4] 2> 324079 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[128]} 0 0
[junit4] 2> 324080 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[129]} 0 0
[junit4] 2> 324081 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[130]} 0 0
[junit4] 2> 324082 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[131]} 0 0
[junit4] 2> 324082 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[132]} 0 0
[junit4] 2> 324083 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[133]} 0 0
[junit4] 2> 324083 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[134]} 0 0
[junit4] 2> 324084 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[135]} 0 0
[junit4] 2> 324084 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[136]} 0 0
[junit4] 2> 324085 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[137]} 0 0
[junit4] 2> 324085 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[138]} 0 0
[junit4] 2> 324086 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[139]} 0 0
[junit4] 2> 324086 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[140]} 0 0
[junit4] 2> 324086 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[141]} 0 0
[junit4] 2> 324087 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[142]} 0 0
[junit4] 2> 324088 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[143]} 0 0
[junit4] 2> 324088 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[144]} 0 0
[junit4] 2> 324089 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[145]} 0 0
[junit4] 2> 324089 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[146]} 0 0
[junit4] 2> 324090 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[147]} 0 0
[junit4] 2> 324090 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[148]} 0 0
[junit4] 2> 324091 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[149]} 0 0
[junit4] 2> 324092 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[150]} 0 0
[junit4] 2> 324092 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[151]} 0 0
[junit4] 2> 324093 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[152]} 0 0
[junit4] 2> 324093 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[153]} 0 0
[junit4] 2> 324094 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[154]} 0 0
[junit4] 2> 324095 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[155]} 0 0
[junit4] 2> 324095 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[156]} 0 0
[junit4] 2> 324096 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[157]} 0 0
[junit4] 2> 324096 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[158]} 0 0
[junit4] 2> 324097 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[159]} 0 0
[junit4] 2> 324098 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[160]} 0 0
[junit4] 2> 324098 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[161]} 0 0
[junit4] 2> 324099 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[162]} 0 0
[junit4] 2> 324099 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[163]} 0 0
[junit4] 2> 324100 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[164]} 0 0
[junit4] 2> 324101 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[165]} 0 0
[junit4] 2> 324101 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[166]} 0 0
[junit4] 2> 324102 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[167]} 0 0
[junit4] 2> 324103 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[168]} 0 0
[junit4] 2> 324103 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[169]} 0 0
[junit4] 2> 324104 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[170]} 0 0
[junit4] 2> 324105 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[171]} 0 0
[junit4] 2> 324105 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[172]} 0 0
[junit4] 2> 324106 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[173]} 0 0
[junit4] 2> 324107 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[174]} 0 0
[junit4] 2> 324107 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[175]} 0 0
[junit4] 2> 324108 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[176]} 0 0
[junit4] 2> 324109 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[177]} 0 0
[junit4] 2> 324109 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[178]} 0 0
[junit4] 2> 324110 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[179]} 0 0
[junit4] 2> 324111 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[180]} 0 0
[junit4] 2> 324111 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[181]} 0 0
[junit4] 2> 324112 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[182]} 0 0
[junit4] 2> 324113 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[183]} 0 0
[junit4] 2> 324113 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[184]} 0 0
[junit4] 2> 324114 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[185]} 0 0
[junit4] 2> 324114 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[186]} 0 0
[junit4] 2> 324115 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[187]} 0 0
[junit4] 2> 324115 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[188]} 0 0
[junit4] 2> 324116 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[189]} 0 0
[junit4] 2> 324117 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[190]} 0 0
[junit4] 2> 324117 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[191]} 0 0
[junit4] 2> 324118 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[192]} 0 0
[junit4] 2> 324119 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[193]} 0 0
[junit4] 2> 324120 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[194]} 0 0
[junit4] 2> 324120 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[195]} 0 0
[junit4] 2> 324121 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[196]} 0 0
[junit4] 2> 324122 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[197]} 0 0
[junit4] 2> 324123 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[198]} 0 0
[junit4] 2> 324127 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[199]} 0 0
[junit4] 2> 324128 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[200]} 0 0
[junit4] 2> 324129 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[201]} 0 0
[junit4] 2> 324129 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[202]} 0 0
[junit4] 2> 324130 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[203]} 0 0
[junit4] 2> 324131 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[204]} 0 0
[junit4] 2> 324132 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[205]} 0 0
[junit4] 2> 324132 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[206]} 0 0
[junit4] 2> 324133 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[207]} 0 0
[junit4] 2> 324133 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[208]} 0 0
[junit4] 2> 324134 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[209]} 0 0
[junit4] 2> 324135 INFO (qtp1145960290-2708) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[210]} 0 0
[junit4] 2> 324136 INFO (qtp1145960290-2710) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[211]} 0 0
[junit4] 2> 324136 INFO (qtp1145960290-2707) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[212]} 0 0
[junit4] 2> 324137 INFO (qtp1145960290-2706) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[213]} 0 0
[junit4] 2> 324138 INFO (qtp1145960290-2704) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[214]} 0 0
[junit4] 2> 324138 INFO (qtp1145960290-2709) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[215]} 0 0
[junit4] 2> 324139 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[216]} 0 0
[junit4] 2> 324140 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[217]} 0 0
[junit4] 2> 324140 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[218]} 0 0
[junit4] 2> 324141 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[219]} 0 0
[junit4] 2> 324141 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[220]} 0 0
[junit4] 2> 324141 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[221]} 0 0
[junit4] 2> 324142 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[222]} 0 0
[junit4] 2> 324142 INFO (qtp1145960290-2703) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[223]} 0 0
[junit4] 2> 324143 INFO (qt
[...truncated too long message...]
registry solr.core.testSimple2.shard1.replica_n2 / com.codahale.metrics.MetricRegistry@32b048db
[junit4] 2> 1397487 INFO (coreCloseExecutor-4395-thread-5) [n:127.0.0.1:50655_solr c:testSimple3 s:shard3 r:core_node6 x:testSimple3_shard3_replica_n4] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.testSimple3.shard3.leader, tag=794593712
[junit4] 2> 1397487 INFO (coreCloseExecutor-4395-thread-3) [n:127.0.0.1:50655_solr c:testSimple3 s:shard1 r:core_node2 x:testSimple3_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.testSimple3.shard1.replica_n1, tag=87217889
[junit4] 2> 1397487 INFO (coreCloseExecutor-4395-thread-3) [n:127.0.0.1:50655_solr c:testSimple3 s:shard1 r:core_node2 x:testSimple3_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6f2b4c8: rootName = solr_50655, domain = solr.core.testSimple3.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.testSimple3.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@f92a20e
[junit4] 2> 1397499 INFO (coreCloseExecutor-4396-thread-3) [n:127.0.0.1:44783_solr c:testSimple2 s:shard1 r:core_node4 x:testSimple2_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.testSimple2.shard1.leader, tag=2119066137
[junit4] 2> 1397502 INFO (jetty-closer-1935-thread-2) [ ] o.a.s.c.Overseer Overseer (id=99245263411216392-127.0.0.1:44783_solr-n_0000000000) closing
[junit4] 2> 1397502 INFO (OverseerStateUpdate-99245263411216392-127.0.0.1:44783_solr-n_0000000000) [n:127.0.0.1:44783_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:44783_solr
[junit4] 2> 1397504 INFO (coreCloseExecutor-4395-thread-3) [n:127.0.0.1:50655_solr c:testSimple3 s:shard1 r:core_node2 x:testSimple3_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.testSimple3.shard1.leader, tag=87217889
[junit4] 2> 1397504 INFO (coreCloseExecutor-4395-thread-4) [n:127.0.0.1:50655_solr c:testSimple3 s:shard2 r:core_node5 x:testSimple3_shard2_replica_n3] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.testSimple3.shard2.replica_n3, tag=1095218848
[junit4] 2> 1397504 INFO (coreCloseExecutor-4395-thread-4) [n:127.0.0.1:50655_solr c:testSimple3 s:shard2 r:core_node5 x:testSimple3_shard2_replica_n3] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7fed0df: rootName = solr_50655, domain = solr.core.testSimple3.shard2.replica_n3, service url = null, agent id = null] for registry solr.core.testSimple3.shard2.replica_n3 / com.codahale.metrics.MetricRegistry@1fb28beb
[junit4] 2> 1397506 WARN (OverseerAutoScalingTriggerThread-99245263411216392-127.0.0.1:44783_solr-n_0000000000) [n:127.0.0.1:44783_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1397515 INFO (zkCallback-1980-thread-3-processing-n:127.0.0.1:50655_solr) [n:127.0.0.1:50655_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:50655_solr
[junit4] 2> 1397517 INFO (jetty-closer-1935-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@79530a4f{/solr,null,UNAVAILABLE}
[junit4] 2> 1397520 INFO (coreCloseExecutor-4395-thread-4) [n:127.0.0.1:50655_solr c:testSimple3 s:shard2 r:core_node5 x:testSimple3_shard2_replica_n3] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.testSimple3.shard2.leader, tag=1095218848
[junit4] 2> 1397525 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x160970a8f44000e, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 1397526 INFO (jetty-closer-1935-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@76c177f4{/solr,null,UNAVAILABLE}
[junit4] 2> 1397528 ERROR (SUITE-AutoAddReplicasPlanActionTest-seed#[97917F4C9451E67B]-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> 1397528 INFO (SUITE-AutoAddReplicasPlanActionTest-seed#[97917F4C9451E67B]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:37251 37251
[junit4] 2> 1407679 INFO (Thread-2046) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:37251 37251
[junit4] 2> 1407680 WARN (Thread-2046) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 5 /solr/aliases.json
[junit4] 2> 5 /solr/clusterprops.json
[junit4] 2> 4 /solr/security.json
[junit4] 2> 4 /solr/configs/conf
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 32 /solr/collections/testSimple1/state.json
[junit4] 2> 14 /solr/collections/testSimple3/state.json
[junit4] 2> 13 /solr/collections/testSimple2/state.json
[junit4] 2> 5 /solr/clusterstate.json
[junit4] 2> 3 /solr/overseer_elect/election/99245263411216392-127.0.0.1:44783_solr-n_0000000000
[junit4] 2> 2 /solr/collections/testSimple1/leader_elect/shard2/election/99245263411216392-core_node7-n_0000000000
[junit4] 2> 2 /solr/collections/testSimple1/leader_elect/shard1/election/99245263411216392-core_node3-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 5 /solr/live_nodes
[junit4] 2> 5 /solr/collections
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.AutoAddReplicasPlanActionTest_97917F4C9451E67B-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=860, maxMBSortInHeap=7.332970119887788, sim=RandomSimilarity(queryNorm=true): {}, locale=fi-FI, timezone=CNT
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_152 (64-bit)/cpus=3,threads=1,free=39899776,total=385118208
[junit4] 2> NOTE: All tests run in this JVM: [DistributedQueueTest, AtomicUpdateProcessorFactoryTest, TestRequestForwarding, ZkSolrClientTest, TestPostingsSolrHighlighter, TestMaxTokenLenTokenizer, TestPKIAuthenticationPlugin, InfoHandlerTest, TestReload, FileUtilsTest, TestComponentsName, SimpleFacetsTest, CollectionsAPIAsyncDistributedZkTest, TestElisionMultitermQuery, TestOverriddenPrefixQueryForCustomFieldType, TestRawResponseWriter, TestXmlQParser, CloudMLTQParserTest, DeleteReplicaTest, TestRestManager, SolrGraphiteReporterTest, TestExactStatsCache, SSLMigrationTest, SolrCloudReportersTest, TestRestoreCore, TestNodeLostTrigger, TestMergePolicyConfig, BlockCacheTest, HdfsSyncSliceTest, TestUtilizeNode, TestSimDistributedQueue, TestSchemaResource, TestCloudRecovery, TestSort, TestUniqueKeyFieldResource, ZkStateWriterTest, DirectSolrSpellCheckerTest, TestConfigSetProperties, TriLevelCompositeIdRoutingTest, TestCSVLoader, IndexSchemaRuntimeFieldTest, TestConfigSetsAPIExclusivity, PolyFieldTest, SolrCloudExampleTest, DeleteStatusTest, TestNumericTerms64, TestClassicSimilarityFactory, TestSolrJ, TestDocBasedVersionConstraints, TestRandomFaceting, TestDistribDocBasedVersion, ConcurrentDeleteAndCreateCollectionTest, LeaderFailoverAfterPartitionTest, TestSuggestSpellingConverter, TestClusterStateMutator, TestMaxScoreQueryParser, TestCloudManagedSchema, TestMultiWordSynonyms, MoreLikeThisHandlerTest, DeleteLastCustomShardedReplicaTest, AddBlockUpdateTest, SuggestComponentContextFilterQueryTest, SystemInfoHandlerTest, SystemLogListenerTest, OverseerTaskQueueTest, TestInfoStreamLogging, ChaosMonkeyNothingIsSafeWithPullReplicasTest, TestLargeCluster, HdfsTlogReplayBufferedWhileIndexingTest, TestInPlaceUpdatesStandalone, TestFastWriter, PingRequestHandlerTest, TestBlobHandler, TestQueryTypes, CollectionStateFormat2Test, TestExecutePlanAction, TermsComponentTest, HdfsWriteToMultipleCollectionsTest, ExplicitHLLTest, DebugComponentTest, RuleEngineTest, CoreAdminHandlerTest, TestDynamicFieldResource, CoreSorterTest, TestLeaderElectionWithEmptyReplica, CdcrVersionReplicationTest, HdfsAutoAddReplicasIntegrationTest, TestFoldingMultitermQuery, TestPullReplica, TestAnalyzedSuggestions, SolrMetricsIntegrationTest, MetricsConfigTest, TestRTimerTree, DocExpirationUpdateProcessorFactoryTest, InfixSuggestersTest, TestIndexSearcher, TestNRTOpen, CoreAdminRequestStatusTest, TolerantUpdateProcessorTest, TestDistributedMissingSort, MetricTriggerTest, PKIAuthenticationIntegrationTest, TestStreamBody, DOMUtilTest, TestCharFilters, DocValuesMultiTest, CursorMarkTest, GraphQueryTest, TestPerFieldSimilarity, TestCoreBackup, QueryResultKeyTest, DistributedFacetSimpleRefinementLongTailTest, PropertiesRequestHandlerTest, DistributedMLTComponentTest, DocumentBuilderTest, ChangedSchemaMergeTest, TestRandomFlRTGCloud, TestBlendedInfixSuggestions, SolrJmxReporterTest, TestComputePlanAction, SampleTest, SpellingQueryConverterTest, TestCustomDocTransformer, TestDistributedGrouping, TestManagedSchema, TestSha256AuthenticationProvider, VersionInfoTest, TestBM25SimilarityFactory, BasicZkTest, TestTrie, LeaderInitiatedRecoveryOnCommitTest, TestSubQueryTransformerCrossCore, AutoAddReplicasPlanActionTest]
[junit4] Completed [238/764 (2!)] on J1 in 24.37s, 1 test, 1 error <<< FAILURES!
[...truncated 49953 lines...]
[JENKINS] Lucene-Solr-7.x-Solaris (64bit/jdk1.8.0) - Build # 356 -
Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Solaris/356/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testSetProperties
Error Message:
Stack Trace:
java.lang.AssertionError
at __randomizedtesting.SeedInfo.seed([98C4F0A068D35A9F:F3A027E9DBFECF1B]:0)
at org.junit.Assert.fail(Assert.java:92)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertTrue(Assert.java:54)
at org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testSetProperties(TriggerIntegrationTest.java:1361)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 13580 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest
[junit4] 2> 3946154 INFO (SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_98C4F0A068D35A9F-001/init-core-data-001
[junit4] 2> 3946154 WARN (SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=24 numCloses=24
[junit4] 2> 3946154 INFO (SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 3946156 INFO (SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 3946156 INFO (SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_98C4F0A068D35A9F-001/tempDir-001
[junit4] 2> 3946156 INFO (SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 3946156 INFO (Thread-8437) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 3946156 INFO (Thread-8437) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 3946159 ERROR (Thread-8437) [ ] 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> 3946256 INFO (SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:34588
[junit4] 2> 3946266 INFO (zkConnectionManagerCallback-4767-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3946288 INFO (jetty-launcher-4764-thread-2) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 3946288 INFO (jetty-launcher-4764-thread-1) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 3946295 INFO (jetty-launcher-4764-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5f0500d3{/solr,null,AVAILABLE}
[junit4] 2> 3946295 INFO (jetty-launcher-4764-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4036f898{/solr,null,AVAILABLE}
[junit4] 2> 3946296 INFO (jetty-launcher-4764-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4785b8ba{HTTP/1.1,[http/1.1]}{127.0.0.1:54064}
[junit4] 2> 3946296 INFO (jetty-launcher-4764-thread-2) [ ] o.e.j.s.Server Started @3950789ms
[junit4] 2> 3946296 INFO (jetty-launcher-4764-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=54064}
[junit4] 2> 3946296 INFO (jetty-launcher-4764-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@37d291f6{HTTP/1.1,[http/1.1]}{127.0.0.1:58429}
[junit4] 2> 3946296 ERROR (jetty-launcher-4764-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 3946296 INFO (jetty-launcher-4764-thread-1) [ ] o.e.j.s.Server Started @3950790ms
[junit4] 2> 3946296 INFO (jetty-launcher-4764-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.0
[junit4] 2> 3946297 INFO (jetty-launcher-4764-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=58429}
[junit4] 2> 3946297 INFO (jetty-launcher-4764-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 3946297 INFO (jetty-launcher-4764-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 3946297 INFO (jetty-launcher-4764-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-12-27T19:39:33.431Z
[junit4] 2> 3946297 ERROR (jetty-launcher-4764-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 3946297 INFO (jetty-launcher-4764-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.0
[junit4] 2> 3946298 INFO (jetty-launcher-4764-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 3946298 INFO (jetty-launcher-4764-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 3946298 INFO (jetty-launcher-4764-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-12-27T19:39:33.432Z
[junit4] 2> 3946301 INFO (zkConnectionManagerCallback-4769-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3946301 INFO (zkConnectionManagerCallback-4771-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3946302 INFO (jetty-launcher-4764-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 3946303 INFO (jetty-launcher-4764-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 3946316 INFO (jetty-launcher-4764-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34588/solr
[junit4] 2> 3946316 INFO (jetty-launcher-4764-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34588/solr
[junit4] 2> 3946318 INFO (zkConnectionManagerCallback-4777-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3946319 INFO (zkConnectionManagerCallback-4779-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3946321 INFO (zkConnectionManagerCallback-4781-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3946322 INFO (zkConnectionManagerCallback-4783-thread-1-processing-n:127.0.0.1:54064_solr) [n:127.0.0.1:54064_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3946462 INFO (jetty-launcher-4764-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 3946463 INFO (jetty-launcher-4764-thread-2) [n:127.0.0.1:54064_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 3946463 INFO (jetty-launcher-4764-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:58429_solr
[junit4] 2> 3946464 INFO (jetty-launcher-4764-thread-2) [n:127.0.0.1:54064_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54064_solr
[junit4] 2> 3946465 INFO (jetty-launcher-4764-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.Overseer Overseer (id=99247952579198981-127.0.0.1:58429_solr-n_0000000000) starting
[junit4] 2> 3946468 INFO (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3946470 INFO (zkCallback-4782-thread-1-processing-n:127.0.0.1:54064_solr) [n:127.0.0.1:54064_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3946479 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 3946481 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 3946481 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:54064_solr]
[junit4] 2> 3946482 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 3946482 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 3946482 INFO (jetty-launcher-4764-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58429_solr
[junit4] 2> 3946483 INFO (zkCallback-4782-thread-1-processing-n:127.0.0.1:54064_solr) [n:127.0.0.1:54064_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 3946484 INFO (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 3946485 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3946485 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 3946486 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3946613 INFO (jetty-launcher-4764-thread-2) [n:127.0.0.1:54064_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_54064.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
[junit4] 2> 3946614 INFO (jetty-launcher-4764-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_58429.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
[junit4] 2> 3946619 INFO (jetty-launcher-4764-thread-2) [n:127.0.0.1:54064_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_54064.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
[junit4] 2> 3946619 INFO (jetty-launcher-4764-thread-2) [n:127.0.0.1:54064_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_54064.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
[junit4] 2> 3946621 INFO (jetty-launcher-4764-thread-2) [n:127.0.0.1:54064_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_98C4F0A068D35A9F-001/tempDir-001/node2/.
[junit4] 2> 3946622 INFO (jetty-launcher-4764-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_58429.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
[junit4] 2> 3946622 INFO (jetty-launcher-4764-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_58429.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
[junit4] 2> 3946623 INFO (jetty-launcher-4764-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_98C4F0A068D35A9F-001/tempDir-001/node1/.
[junit4] 2> 3946653 INFO (zkConnectionManagerCallback-4789-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3946656 INFO (zkConnectionManagerCallback-4793-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3946658 INFO (SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 3946659 INFO (SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34588/solr ready
[junit4] 2> 3946784 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTriggerRestoreState
[junit4] 2> 3946785 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 2
[junit4] 2> 3946786 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 3946786 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 3946791 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3946792 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3946792 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 3946797 INFO (qtp1937897085-31620) [n:127.0.0.1:54064_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3946799 INFO (qtp1298289486-31612) [n:127.0.0.1:58429_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3946800 DEBUG (qtp1937897085-31617) [n:127.0.0.1:54064_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3946800 INFO (qtp1937897085-31617) [n:127.0.0.1:54064_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 3946801 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 3946801 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 3946804 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:54064_solr, 127.0.0.1:58429_solr]
[junit4] 2> 3946804 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_restore_trigger instantiated with properties: {event=nodeAdded, waitFor=5, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}], enabled=true}
[junit4] 2> 3946804 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 3946805 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@659a3066{/solr,null,AVAILABLE}
[junit4] 2> 3946806 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6d25db28{HTTP/1.1,[http/1.1]}{127.0.0.1:60345}
[junit4] 2> 3946806 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.e.j.s.Server Started @3951299ms
[junit4] 2> 3946806 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=60345}
[junit4] 2> 3946806 ERROR (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 3946806 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.0
[junit4] 2> 3946806 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 3946806 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 3946806 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-12-27T19:39:33.940Z
[junit4] 2> 3946807 INFO (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init
[junit4] 2> 3946810 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3946810 INFO (zkConnectionManagerCallback-4795-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3946811 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 3946811 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_restore_trigger
[junit4] 2> 3946811 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3946811 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 3946819 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34588/solr
[junit4] 2> 3946821 INFO (zkConnectionManagerCallback-4799-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3946824 INFO (zkConnectionManagerCallback-4801-thread-1-processing-n:127.0.0.1:60345_solr) [n:127.0.0.1:60345_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3946836 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [n:127.0.0.1:60345_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 3946840 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [n:127.0.0.1:60345_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 3946843 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [n:127.0.0.1:60345_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60345_solr
[junit4] 2> 3946845 INFO (zkCallback-4782-thread-1-processing-n:127.0.0.1:54064_solr) [n:127.0.0.1:54064_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 3946845 INFO (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 3946847 INFO (zkCallback-4800-thread-1-processing-n:127.0.0.1:60345_solr) [n:127.0.0.1:60345_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 3946847 INFO (zkCallback-4792-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 3946949 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [n:127.0.0.1:60345_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_60345.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
[junit4] 2> 3946956 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [n:127.0.0.1:60345_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_60345.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
[junit4] 2> 3946956 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [n:127.0.0.1:60345_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_60345.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
[junit4] 2> 3946957 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [n:127.0.0.1:60345_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_98C4F0A068D35A9F-001/tempDir-001/node3/.
[junit4] 2> 3947821 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_restore_trigger
[junit4] 2> 3947822 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3947822 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:60345_solr at time 2147034263632547
[junit4] 2> 3948488 INFO (qtp1937897085-31622) [n:127.0.0.1:54064_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3948489 INFO (qtp1298289486-31613) [n:127.0.0.1:58429_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3948492 INFO (qtp1955971146-31672) [n:127.0.0.1:60345_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3948492 DEBUG (qtp1937897085-31621) [n:127.0.0.1:54064_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3948494 INFO (qtp1937897085-31621) [n:127.0.0.1:54064_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=7
[junit4] 2> 3948495 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 3948496 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:54064_solr, 127.0.0.1:58429_solr, 127.0.0.1:60345_solr]
[junit4] 2> 3948496 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_restore_trigger instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}], enabled=true}
[junit4] 2> 3948496 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 3948498 INFO (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init
[junit4] 2> 3948499 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Adding node from marker path: 127.0.0.1:60345_solr
[junit4] 2> 3948501 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3948501 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_restore_trigger
[junit4] 2> 3948501 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3948501 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_restore_trigger firing registered processor for nodes: [127.0.0.1:60345_solr] added at times [2147034940848485], now=2147034943121521
[junit4] 2> 3948501 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"7a0b786f83965Tbs5gkwc63xlxd6sdmd1kwv4d9",
[junit4] 2> "source":"node_added_restore_trigger",
[junit4] 2> "eventTime":2147034940848485,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147034940848485],
[junit4] 2> "nodeNames":["127.0.0.1:60345_solr"]}}
[junit4] 2> 3948502 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 3948503 INFO (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging.
[junit4] 2> 3948504 DEBUG (AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"7a0b786f83965Tbs5gkwc63xlxd6sdmd1kwv4d9",
[junit4] 2> "source":"node_added_restore_trigger",
[junit4] 2> "eventTime":2147034940848485,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147034940848485],
[junit4] 2> "_enqueue_time_":2147034943399442,
[junit4] 2> "nodeNames":["127.0.0.1:60345_solr"]}}
[junit4] 2> 3948505 INFO (TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeAddedTriggerRestoreState
[junit4] 2> 3948516 DEBUG (AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 12 ms for event id=7a0b786f83965Tbs5gkwc63xlxd6sdmd1kwv4d9
[junit4] 2> 3948683 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTriggerThrottling
[junit4] 2> 3948683 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 5
[junit4] 2> 3948684 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 3948684 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 3948688 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3948688 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3948689 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 3948693 INFO (qtp1937897085-31623) [n:127.0.0.1:54064_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3948694 INFO (qtp1298289486-31614) [n:127.0.0.1:58429_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3948695 INFO (qtp1955971146-31676) [n:127.0.0.1:60345_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3948695 DEBUG (qtp1955971146-31674) [n:127.0.0.1:60345_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3948696 INFO (qtp1955971146-31674) [n:127.0.0.1:60345_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 3948696 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
[junit4] 2> 3948697 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:54064_solr, 127.0.0.1:58429_solr, 127.0.0.1:60345_solr]
[junit4] 2> 3948697 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 3948697 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
[junit4] 2> 3948697 INFO (qtp1937897085-31608) [n:127.0.0.1:54064_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3948698 INFO (qtp1298289486-31616) [n:127.0.0.1:58429_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3948698 INFO (qtp1955971146-31670) [n:127.0.0.1:60345_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3948698 DEBUG (qtp1955971146-31677) [n:127.0.0.1:60345_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3948699 INFO (qtp1955971146-31677) [n:127.0.0.1:60345_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 3948700 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
[junit4] 2> 3948700 INFO (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init
[junit4] 2> 3948700 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:54064_solr, 127.0.0.1:58429_solr, 127.0.0.1:60345_solr]
[junit4] 2> 3948700 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 3948700 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3948701 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:54064_solr, 127.0.0.1:58429_solr, 127.0.0.1:60345_solr]
[junit4] 2> 3948701 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 3948701 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 6
[junit4] 2> 3948701 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
[junit4] 2> 3948701 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 3948701 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3948704 INFO (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init
[junit4] 2> 3948704 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 3948705 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3948705 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 3948705 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 3948705 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3948706 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@55dacf4e{/solr,null,AVAILABLE}
[junit4] 2> 3948707 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5d54764b{HTTP/1.1,[http/1.1]}{127.0.0.1:33919}
[junit4] 2> 3948707 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.e.j.s.Server Started @3953201ms
[junit4] 2> 3948707 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=33919}
[junit4] 2> 3948707 ERROR (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 3948707 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.0
[junit4] 2> 3948707 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 3948707 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 3948707 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-12-27T19:39:35.841Z
[junit4] 2> 3948709 INFO (zkConnectionManagerCallback-4805-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3948710 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 3948718 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34588/solr
[junit4] 2> 3948720 INFO (zkConnectionManagerCallback-4809-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3948723 INFO (zkConnectionManagerCallback-4811-thread-1-processing-n:127.0.0.1:33919_solr) [n:127.0.0.1:33919_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3948733 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [n:127.0.0.1:33919_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 3948736 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [n:127.0.0.1:33919_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 3948738 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [n:127.0.0.1:33919_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33919_solr
[junit4] 2> 3948740 INFO (zkCallback-4782-thread-1-processing-n:127.0.0.1:54064_solr) [n:127.0.0.1:54064_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 3948742 INFO (zkCallback-4810-thread-1-processing-n:127.0.0.1:33919_solr) [n:127.0.0.1:33919_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 3948742 INFO (zkCallback-4800-thread-1-processing-n:127.0.0.1:60345_solr) [n:127.0.0.1:60345_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 3948742 INFO (zkCallback-4792-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 3948743 INFO (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 3948879 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [n:127.0.0.1:33919_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33919.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
[junit4] 2> 3948885 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [n:127.0.0.1:33919_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33919.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
[junit4] 2> 3948885 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [n:127.0.0.1:33919_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33919.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
[junit4] 2> 3948886 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [n:127.0.0.1:33919_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_98C4F0A068D35A9F-001/tempDir-001/node4/.
[junit4] 2> 3949703 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 3949704 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 3949704 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:33919_solr at time 2147036146069577
[junit4] 2> 3949704 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 firing registered processor for nodes: [127.0.0.1:33919_solr] added at times [2147036146069577], now=2147036146172633
[junit4] 2> 3949704 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"7a0b7cece7049Tbs5gkwc63xlxd6sdmd1kwv4db",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":2147036146069577,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147036146069577],
[junit4] 2> "nodeNames":["127.0.0.1:33919_solr"]}}
[junit4] 2> 3949706 INFO (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging.
[junit4] 2> 3949706 DEBUG (AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"7a0b7cece7049Tbs5gkwc63xlxd6sdmd1kwv4db",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":2147036146069577,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147036146069577],
[junit4] 2> "_enqueue_time_":2147036146512691,
[junit4] 2> "nodeNames":["127.0.0.1:33919_solr"]}}
[junit4] 2> 3949706 INFO (AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.TriggerIntegrationTest action executed from node_added_trigger1
[junit4] 2> 3949709 DEBUG (AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 2 ms for event id=7a0b7cece7049Tbs5gkwc63xlxd6sdmd1kwv4db
[junit4] 2> 3950721 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 3950721 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 3950721 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 3950721 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:33919_solr at time 2147037163822023
[junit4] 2> 3950721 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:33919_solr] added at times [2147037163822023], now=2147037163986288
[junit4] 2> 3950721 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 3950722 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"7a0b80b781bc7Tbs5gkwc63xlxd6sdmd1kwv4dd",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":2147037163822023,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147037163822023],
[junit4] 2> "nodeNames":["127.0.0.1:33919_solr"]}}
[junit4] 2> 3950722 INFO (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging.
[junit4] 2> 3951737 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 3951737 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 3951737 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 3951737 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 3951737 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:33919_solr] added at times [2147037163822023], now=2147038179893926
[junit4] 2> 3951737 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"7a0b80b781bc7Tbs5gkwc63xlxd6sdmd1kwv4df",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":2147037163822023,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147037163822023],
[junit4] 2> "nodeNames":["127.0.0.1:33919_solr"]}}
[junit4] 2> 3952741 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 3952741 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 3952741 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 3952741 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 3952741 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:33919_solr] added at times [2147037163822023], now=2147039184524364
[junit4] 2> 3952742 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"7a0b80b781bc7Tbs5gkwc63xlxd6sdmd1kwv4dg",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":2147037163822023,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147037163822023],
[junit4] 2> "nodeNames":["127.0.0.1:33919_solr"]}}
[junit4] 2> 3953743 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 3953743 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 3953743 DEBUG (ScheduledTrigger-11018-thread-3) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 3953743 DEBUG (ScheduledTrigger-11018-thread-3) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 3953743 DEBUG (ScheduledTrigger-11018-thread-3) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:33919_solr] added at times [2147037163822023], now=2147040186742926
[junit4] 2> 3953743 DEBUG (ScheduledTrigger-11018-thread-3) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"7a0b80b781bc7Tbs5gkwc63xlxd6sdmd1kwv4dh",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":2147037163822023,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147037163822023],
[junit4] 2> "nodeNames":["127.0.0.1:33919_solr"]}}
[junit4] 2> 3954744 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 3954744 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 3954744 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 3954744 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 3954744 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:33919_solr] added at times [2147037163822023], now=2147041188043373
[junit4] 2> 3954745 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"7a0b80b781bc7Tbs5gkwc63xlxd6sdmd1kwv4di",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":2147037163822023,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147037163822023],
[junit4] 2> "nodeNames":["127.0.0.1:33919_solr"]}}
[junit4] 2> 3954746 DEBUG (AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"7a0b80b781bc7Tbs5gkwc63xlxd6sdmd1kwv4di",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":2147037163822023,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147037163822023],
[junit4] 2> "_enqueue_time_":2147041188367959,
[junit4] 2> "nodeNames":["127.0.0.1:33919_solr"]}}
[junit4] 2> 3954747 INFO (AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.TriggerIntegrationTest last action at 1514403576840000000 current time = 1514403581880000000
[junit4] 2> real diff: 5040000000
[junit4] 2> min diff: 4998000000
[junit4] 2> 3954747 INFO (AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.TriggerIntegrationTest action executed from node_added_trigger2
[junit4] 2> 3954750 DEBUG (AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 3 ms for event id=7a0b80b781bc7Tbs5gkwc63xlxd6sdmd1kwv4di
[junit4] 2> 3954752 INFO (qtp1573688417-31701) [n:127.0.0.1:33919_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3954754 INFO (qtp1937897085-31618) [n:127.0.0.1:54064_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3954757 INFO (qtp1298289486-31619) [n:127.0.0.1:58429_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3954759 INFO (qtp1955971146-31673) [n:127.0.0.1:60345_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3954760 DEBUG (qtp1955971146-31672) [n:127.0.0.1:60345_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3954761 INFO (qtp1955971146-31672) [n:127.0.0.1:60345_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=12
[junit4] 2> 3954762 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8
[junit4] 2> 3954764 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:54064_solr, 127.0.0.1:33919_solr, 127.0.0.1:58429_solr, 127.0.0.1:60345_solr]
[junit4] 2> 3954764 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 3954765 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:54064_solr, 127.0.0.1:33919_solr, 127.0.0.1:58429_solr, 127.0.0.1:60345_solr]
[junit4] 2> 3954766 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:54064_solr, 127.0.0.1:33919_solr, 127.0.0.1:58429_solr, 127.0.0.1:60345_solr]
[junit4] 2> 3954766 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 3954766 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8
[junit4] 2> 3954766 INFO (qtp1573688417-31703) [n:127.0.0.1:33919_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3954768 INFO (qtp1937897085-31617) [n:127.0.0.1:54064_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3954771 INFO (qtp1298289486-31609) [n:127.0.0.1:58429_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3954772 INFO (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init
[junit4] 2> 3954773 INFO (qtp1955971146-31675) [n:127.0.0.1:60345_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 QTime=0
[junit4] 2> 3954773 DEBUG (qtp1937897085-31620) [n:127.0.0.1:54064_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3954774 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 3954775 INFO (qtp1937897085-31620) [n:127.0.0.1:54064_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=11
[junit4] 2> 3954775 DEBUG (ScheduledTrigger-11018-thread-3) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger1 with currently live nodes: 4
[junit4] 2> 3954776 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9
[junit4] 2> 3954777 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:54064_solr, 127.0.0.1:33919_solr, 127.0.0.1:58429_solr, 127.0.0.1:60345_solr]
[junit4] 2> 3954777 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 3954778 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:54064_solr, 127.0.0.1:33919_solr, 127.0.0.1:58429_solr, 127.0.0.1:60345_solr]
[junit4] 2> 3954779 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:54064_solr, 127.0.0.1:33919_solr, 127.0.0.1:58429_solr, 127.0.0.1:60345_solr]
[junit4] 2> 3954779 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 3954780 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:54064_solr, 127.0.0.1:33919_solr, 127.0.0.1:58429_solr, 127.0.0.1:60345_solr]
[junit4] 2> 3954780 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9
[junit4] 2> 3954788 INFO (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init
[junit4] 2> 3954789 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 3954791 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger2 with currently live nodes: 4
[junit4] 2> 3954792 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@5d54764b{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 3954792 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=411375952
[junit4] 2> 3954792 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 3954792 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@36f36df4: rootName = solr_33919, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@111873a
[junit4] 2> 3954802 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 3954802 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7375684: rootName = solr_33919, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@1e8d67f
[junit4] 2> 3954808 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 3954808 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@75f2c8d3: rootName = solr_33919, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@5cdb696a
[junit4] 2> 3954811 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:33919_solr
[junit4] 2> 3954812 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 3954812 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 3954812 INFO (zkCallback-4810-thread-1-processing-n:127.0.0.1:33919_solr) [n:127.0.0.1:33919_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 3954813 INFO (zkCallback-4792-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 3954813 INFO (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 3954814 INFO (zkCallback-4782-thread-1-processing-n:127.0.0.1:54064_solr) [n:127.0.0.1:54064_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 3954814 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x160997cae2b000e, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 3954814 INFO (zkCallback-4800-thread-1-processing-n:127.0.0.1:60345_solr) [n:127.0.0.1:60345_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 3955745 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 3955746 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3955748 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 3955748 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3955777 DEBUG (ScheduledTrigger-11018-thread-3) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger1 with currently live nodes: 3
[junit4] 2> 3955777 DEBUG (ScheduledTrigger-11018-thread-3) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:33919_solr
[junit4] 2> 3955777 DEBUG (ScheduledTrigger-11018-thread-3) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:33919_solr]
[junit4] 2> 3955777 DEBUG (ScheduledTrigger-11018-thread-3) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"7a0b938e1abc1Tbs5gkwc63xlxd6sdmd1kwv4dj",
[junit4] 2> "source":"node_lost_trigger1",
[junit4] 2> "eventTime":2147042220682177,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147042220682177],
[junit4] 2> "nodeNames":["127.0.0.1:33919_solr"]}}
[junit4] 2> 3955778 INFO (ScheduledTrigger-11018-thread-3) [n:127.0.0.1:58429_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging.
[junit4] 2> 3955778 DEBUG (AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"7a0b938e1abc1Tbs5gkwc63xlxd6sdmd1kwv4dj",
[junit4] 2> "source":"node_lost_trigger1",
[junit4] 2> "eventTime":2147042220682177,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147042220682177],
[junit4] 2> "_enqueue_time_":2147042220859416,
[junit4] 2> "nodeNames":["127.0.0.1:33919_solr"]}}
[junit4] 2> 3955778 INFO (AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.TriggerIntegrationTest action executed from node_lost_trigger1
[junit4] 2> 3955779 DEBUG (AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 1 ms for event id=7a0b938e1abc1Tbs5gkwc63xlxd6sdmd1kwv4dj
[junit4] 2> 3955792 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger2 with currently live nodes: 3
[junit4] 2> 3955792 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:33919_solr
[junit4] 2> 3955792 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:33919_solr]
[junit4] 2> 3955792 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"7a0b939ce9c54Tbs5gkwc63xlxd6sdmd1kwv4dl",
[junit4] 2> "source":"node_lost_trigger2",
[junit4] 2> "eventTime":2147042236210260,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147042236210260],
[junit4] 2> "nodeNames":["127.0.0.1:33919_solr"]}}
[junit4] 2> 3955792 INFO (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging.
[junit4] 2> 3955792 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:33919_solr] is not ready, will try later
[junit4] 2> 3956314 WARN (zkCallback-4810-thread-1-processing-n:127.0.0.1:33919_solr) [n:127.0.0.1:33919_solr ] o.a.s.c.ZkController Unable to register nodeLost path for 127.0.0.1:33919_solr
[junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /autoscaling/nodeLost/127.0.0.1:33919_solr
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.lambda$create$7(SolrZkClient.java:364)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:364)
[junit4] 2> at org.apache.solr.cloud.ZkController.lambda$registerLiveNodesListener$2(ZkController.java:879)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.lambda$refreshLiveNodes$1(ZkStateReader.java:704)
[junit4] 2> at java.util.concurrent.ConcurrentHashMap$KeySetView.forEach(ConcurrentHashMap.java:4649)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.refreshLiveNodes(ZkStateReader.java:703)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.access$900(ZkStateReader.java:72)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.refreshAndWatch(ZkStateReader.java:1090)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.process(ZkStateReader.java:1085)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$1.lambda$process$1(SolrZkClient.java:268)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 3956315 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@55dacf4e{/solr,null,UNAVAILABLE}
[junit4] 2> 3956752 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 3956752 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 3956752 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3956752 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3956779 DEBUG (ScheduledTrigger-11018-thread-3) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger1 with currently live nodes: 3
[junit4] 2> 3956793 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger2 with currently live nodes: 3
[junit4] 2> 3956793 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:33919_solr]
[junit4] 2> 3956794 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"7a0b939ce9c54Tbs5gkwc63xlxd6sdmd1kwv4dn",
[junit4] 2> "source":"node_lost_trigger2",
[junit4] 2> "eventTime":2147042236210260,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147042236210260],
[junit4] 2> "nodeNames":["127.0.0.1:33919_solr"]}}
[junit4] 2> 3956794 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:33919_solr] is not ready, will try later
[junit4] 2> 3957753 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 3957753 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3957753 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 3957753 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3957780 DEBUG (ScheduledTrigger-11018-thread-3) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger1 with currently live nodes: 3
[junit4] 2> 3957794 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger2 with currently live nodes: 3
[junit4] 2> 3957794 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:33919_solr]
[junit4] 2> 3957794 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"7a0b939ce9c54Tbs5gkwc63xlxd6sdmd1kwv4do",
[junit4] 2> "source":"node_lost_trigger2",
[junit4] 2> "eventTime":2147042236210260,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147042236210260],
[junit4] 2> "nodeNames":["127.0.0.1:33919_solr"]}}
[junit4] 2> 3957794 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:33919_solr] is not ready, will try later
[junit4] 2> 3958754 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 3958754 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 3958754 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3958754 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3958780 DEBUG (ScheduledTrigger-11018-thread-3) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger1 with currently live nodes: 3
[junit4] 2> 3958794 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger2 with currently live nodes: 3
[junit4] 2> 3958795 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:33919_solr]
[junit4] 2> 3958795 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"7a0b939ce9c54Tbs5gkwc63xlxd6sdmd1kwv4dp",
[junit4] 2> "source":"node_lost_trigger2",
[junit4] 2> "eventTime":2147042236210260,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147042236210260],
[junit4] 2> "nodeNames":["127.0.0.1:33919_solr"]}}
[junit4] 2> 3958795 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:33919_solr] is not ready, will try later
[junit4] 2> 3959755 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 3959756 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 3959756 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3959756 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3959780 DEBUG (ScheduledTrigger-11018-thread-3) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger1 with currently live nodes: 3
[junit4] 2> 3959795 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger2 with currently live nodes: 3
[junit4] 2> 3959795 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:33919_solr]
[junit4] 2> 3959795 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"7a0b939ce9c54Tbs5gkwc63xlxd6sdmd1kwv4dq",
[junit4] 2> "source":"node_lost_trigger2",
[junit4] 2> "eventTime":2147042236210260,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147042236210260],
[junit4] 2> "nodeNames":["127.0.0.1:33919_solr"]}}
[junit4] 2> 3959795 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:33919_solr] is not ready, will try later
[junit4] 2> 3960757 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 3960757 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 3960757 DEBUG (ScheduledTrigger-11018-thread-1) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3960757 DEBUG (ScheduledTrigger-11018-thread-4) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3960780 DEBUG (ScheduledTrigger-11018-thread-3) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger1 with currently live nodes: 3
[junit4] 2> 3960796 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger2 with currently live nodes: 3
[junit4] 2> 3960796 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:33919_solr]
[junit4] 2> 3960796 DEBUG (ScheduledTrigger-11018-thread-2) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"7a0b939ce9c54Tbs5gkwc63xlxd6sdmd1kwv4dr",
[junit4] 2> "source":"node_lost_trigger2",
[junit4] 2> "eventTime":2147042236210260,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147042236210260],
[junit4] 2> "nodeNames":["127.0.0.1:33919_solr"]}}
[junit4] 2> 3960797 DEBUG (AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"7a0b939ce9c54Tbs5gkwc63xlxd6sdmd1kwv4dr",
[junit4] 2> "source":"node_lost_trigger2",
[junit4] 2> "eventTime":2147042236210260,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2147042236210260],
[junit4] 2> "_enqueue_time_":2147047241146965,
[junit4] 2> "nodeNames":["127.0.0.1:33919_solr"]}}
[junit4] 2> 3960798 INFO (AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.TriggerIntegrationTest last action at 1514403582912000000 current time = 1514403587932000000
[junit4] 2> real diff: 5020000000
[junit4] 2> min diff: 4998000000
[junit4] 2> 3960798 INFO (AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.TriggerIntegrationTest action executed from node_lost_trigger2
[junit4] 2> 3960798 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTriggerThrottling
[junit4] 2> 3960830 DEBUG (AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 33 ms for event id=7a0b939ce9c54Tbs5gkwc63xlxd6sdmd1kwv4dr
[junit4] 2> 3960961 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTriggerRestoreState
[junit4] 2> 3960961 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 10
[junit4] 2> 3960962 DEBUG (zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10
[junit4] 2> 3960962 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10
[junit4] 2> 3960971 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3960971 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3960972 DEBUG (OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000) [n:127.0.0.1:58429_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10
[junit4] 2> 3960972 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 3960973 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@ced492d{/solr,null,AVAILABLE}
[junit4] 2> 3960973 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@b3ebf76{HTTP/1.1,[http/1.1]}{127.0.0.1:38524}
[junit4] 2> 3960973 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.e.j.s.Server Started @3965471ms
[junit4] 2> 3960973 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[98C4F0A068D35A9F]) [ ] o.a.s.c.s.e.JettySolrRunne
[...truncated too long message...]
l.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 4122389 INFO (jetty-closer-4765-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2f5449f1{/solr,null,UNAVAILABLE}
[junit4] 2> 4122393 ERROR (SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-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> 4122395 INFO (SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:34588 34588
[junit4] 2> 4127624 INFO (Thread-8437) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:34588 34588
[junit4] 2> 4127641 WARN (Thread-8437) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 20 /solr/aliases.json
[junit4] 2> 20 /solr/clusterprops.json
[junit4] 2> 19 /solr/security.json
[junit4] 2> 3 /solr/configs/conf
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 26 /solr/collections/testMetricTrigger/state.json
[junit4] 2> 20 /solr/clusterstate.json
[junit4] 2> 6 /solr/autoscaling.json
[junit4] 2> 3 /solr/overseer_elect/election/99247952579198987-127.0.0.1:60345_solr-n_0000000002
[junit4] 2> 2 /solr/overseer_elect/election/99247952579199005-127.0.0.1:48212_solr-n_0000000008
[junit4] 2> 2 /solr/overseer_elect/election/99247952579199021-127.0.0.1:63784_solr-n_0000000013
[junit4] 2> 2 /solr/overseer_elect/election/99247952579199015-127.0.0.1:65274_solr-n_0000000011
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 20 /solr/live_nodes
[junit4] 2> 20 /solr/collections
[junit4] 2> 6 /solr/overseer/queue-work
[junit4] 2> 6 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 6 /solr/overseer/queue
[junit4] 2> 6 /solr/overseer/collection-queue-work
[junit4] 2> 3 /solr/autoscaling/events/node_added_trigger
[junit4] 2> 2 /solr/autoscaling/events/node_lost_trigger
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_98C4F0A068D35A9F-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {id=Lucene50(blocksize=128), x_s=PostingsFormat(name=MockRandom)}, docValues:{}, maxPointsInLeafNode=1216, maxMBSortInHeap=5.4596507488744495, sim=RandomSimilarity(queryNorm=true): {}, locale=es, timezone=Africa/Timbuktu
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_152 (64-bit)/cpus=3,threads=1,free=292399688,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [RuleEngineTest, MultiThreadedOCPTest, ExitableDirectoryReaderTest, QueryResultKeyTest, BadComponentTest, HdfsRecoveryZkTest, TermVectorComponentTest, AnalysisAfterCoreReloadTest, BadCopyFieldTest, TestLMJelinekMercerSimilarityFactory, TestSolrQueryParser, MBeansHandlerTest, DistanceUnitsTest, TestHdfsUpdateLog, TestAuthenticationFramework, InfixSuggestersTest, BufferStoreTest, TestUniqueKeyFieldResource, TestRandomFlRTGCloud, ParsingFieldUpdateProcessorsTest, OutOfBoxZkACLAndCredentialsProvidersTest, TestPKIAuthenticationPlugin, SystemInfoHandlerTest, TestNumericRangeQuery64, TestUtilizeNode, TestMultiWordSynonyms, TestReplicationHandlerBackup, SimpleFacetsTest, BasicZkTest, TestFieldTypeResource, TestCrossCoreJoin, TestCryptoKeys, TestPayloadScoreQParserPlugin, TestRawResponseWriter, TestCharFilters, TestPostingsSolrHighlighter, CollectionsAPIDistributedZkTest, TestPullReplica, TestConfigSetsAPIExclusivity, TestLuceneMatchVersion, ClassificationUpdateProcessorFactoryTest, TestTrie, EchoParamsTest, DocumentAnalysisRequestHandlerTest, TestSolrConfigHandlerConcurrent, DeleteLastCustomShardedReplicaTest, DistributedQueryComponentCustomSortTest, TestCollationField, TestSolrCloudWithKerberosAlt, TestSkipOverseerOperations, TestConfigsApi, LukeRequestHandlerTest, TestInPlaceUpdatesStandalone, DocValuesNotIndexedTest, TestCloudPivotFacet, PolyFieldTest, ZkStateWriterTest, ExternalFileFieldSortTest, TestAnalyzedSuggestions, LeaderInitiatedRecoveryOnCommitTest, TestSimpleTrackingShardHandler, CacheHeaderTest, SuggestComponentContextFilterQueryTest, TestSuggestSpellingConverter, TestMergePolicyConfig, PreAnalyzedFieldTest, TestSimDistributedQueue, TestDistribIDF, ComputePlanActionTest, TestDocSet, TestNodeLostTrigger, TestLegacyFieldCache, CachingDirectoryFactoryTest, DebugComponentTest, WrapperMergePolicyFactoryTest, TestConfig, TestSQLHandlerNonCloud, TestCollapseQParserPlugin, TestNumericTerms64, TestLeaderInitiatedRecoveryThread, TestInitQParser, TestSolrConfigHandler, TestUseDocValuesAsStored, TestRandomFaceting, TestXmlQParser, TestGraphTermsQParserPlugin, JsonLoaderTest, TestQueryTypes, CoreSorterTest, SolrGraphiteReporterTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest, HdfsLockFactoryTest, TermsComponentTest, PeerSyncTest, TestGeoJSONResponseWriter, BigEndianAscendingWordSerializerTest, HdfsBasicDistributedZkTest, SolrPluginUtilsTest, ReplaceNodeTest, ChangedSchemaMergeTest, TestCloudInspectUtil, TestStressLucene, SearchHandlerTest, TestGroupingSearch, FieldMutatingUpdateProcessorTest, SSLMigrationTest, SystemLogListenerTest, TestOrdValues, DocValuesMultiTest, OpenCloseCoreStressTest, TestPartialUpdateDeduplication, SparseHLLTest, PKIAuthenticationIntegrationTest, BaseCdcrDistributedZkTest, TestExclusionRuleCollectionAccess, TestOnReconnectListenerSupport, CustomCollectionTest, TestRTGBase, TestSolrJ, TestDistributedStatsComponentCardinality, ZkFailoverTest, VersionInfoTest, SOLR749Test, SpellPossibilityIteratorTest, CollectionsAPIAsyncDistributedZkTest, TestZkAclsWithHadoopAuth, HLLSerializationTest, TestBadConfig, TestSearchPerf, MergeStrategyTest, RecoveryAfterSoftCommitTest, TestRequestForwarding, LoggingHandlerTest, DOMUtilTest, QueryElevationComponentTest, DistributedMLTComponentTest, HdfsChaosMonkeySafeLeaderTest, DirectSolrSpellCheckerTest, TestComplexPhraseQParserPlugin, SpatialRPTFieldTypeTest, TestExtendedDismaxParser, TestLegacyField, ShardSplitTest, OverseerTaskQueueTest, TestElisionMultitermQuery, AutoscalingHistoryHandlerTest, SoftAutoCommitTest, TestFieldSortValues, TestConfigOverlay, ZkSolrClientTest, TestManagedSchemaThreadSafety, CollectionStateFormat2Test, SimplePostToolTest, TestTolerantUpdateProcessorCloud, TestLeaderElectionWithEmptyReplica, MetricTriggerTest, TestHashPartitioner, TestZkChroot, TestSystemIdResolver, TestLuceneIndexBackCompat, AtomicUpdateProcessorFactoryTest, TestJsonFacets, TestMaxScoreQueryParser, QueryEqualityTest, TestFieldCacheVsDocValues, HttpPartitionTest, TestStressReorder, SpellCheckCollatorWithCollapseTest, TestDocBasedVersionConstraints, TestIndexSearcher, TestFieldCache, TestFieldCacheSort, DateRangeFieldTest, TestClusterStateMutator, TestFastLRUCache, UpdateParamsTest, MissingSegmentRecoveryTest, TestCoreBackup, SolrJmxReporterTest, HdfsTlogReplayBufferedWhileIndexingTest, TestPerFieldSimilarity, GraphQueryTest, TestConfigSetProperties, TestSolr4Spatial2, TestDistributedMissingSort, DocumentBuilderTest, InfoHandlerTest, BasicDistributedZkTest, TestReplicationHandler, TestDistributedGrouping, TestFaceting, TermVectorComponentDistributedTest, ZkControllerTest, TestStressVersions, SolrCoreTest, SolrCmdDistributorTest, TestFunctionQuery, TestLazyCores, SignatureUpdateProcessorFactoryTest, CoreAdminHandlerTest, DocValuesTest, TestRemoteStreaming, DistanceFunctionTest, TestSurroundQueryParser, TestQueryUtils, TestReversedWildcardFilterFactory, FileBasedSpellCheckerTest, RequestHandlersTest, TestValueSourceCache, RequiredFieldsTest, FieldAnalysisRequestHandlerTest, IndexSchemaRuntimeFieldTest, UpdateRequestProcessorFactoryTest, QueryParsingTest, CSVRequestHandlerTest, TestComponentsName, HighlighterConfigTest, TestQuerySenderListener, TestSolrIndexConfig, CopyFieldTest, SolrIndexConfigTest, TestSolrDeletionPolicy2, MultiTermTest, SampleTest, TestBinaryField, NumericFieldsTest, OutputWriterTest, DirectSolrConnectionTest, TestPhraseSuggestions, SynonymTokenizerTest, TestSweetSpotSimilarityFactory, TestDFRSimilarityFactory, TestLMDirichletSimilarityFactory, TestBM25SimilarityFactory, TestFastWriter, ResourceLoaderTest, TestFastOutputStream, ScriptEngineTest, OpenExchangeRatesOrgProviderTest, URLClassifyProcessorTest, PluginInfoTest, PrimUtilsTest, DateFieldTest, SpellingQueryConverterTest, TestLRUCache, TestUtils, TestDocumentBuilder, ZkNodePropsTest, SliceStateTest, UUIDFieldTest, FileUtilsTest, CircularListTest, CursorPagingTest, SolrTestCaseJ4Test, TestJettySolrRunner, ConnectionReuseTest, AliasIntegrationTest, AssignTest, CloudExitableDirectoryReaderTest, ConcurrentDeleteAndCreateCollectionTest, ConfigSetsAPITest, CreateCollectionCleanupTest, DeleteShardTest, DistribCursorPagingTest, DistribJoinFromCollectionTest, DistributedQueueTest, LeaderFailoverAfterPartitionTest, MoveReplicaHDFSTest, SolrCloudExampleTest, TestCloudRecovery, TestDistribDocBasedVersion, TestLeaderElectionZkExpiry, TestLockTree, TestPullReplicaErrorHandling, TestRequestStatusCollectionAPI, TestSolrCloudWithDelegationTokens, TestSolrCloudWithSecureImpersonation, VMParamsZkACLAndCredentialsProvidersTest, AutoScalingHandlerTest, HdfsAutoAddReplicasIntegrationTest, TriggerIntegrationTest]
[junit4] Completed [579/764 (1!)] on J1 in 181.55s, 14 tests, 1 failure, 1 skipped <<< FAILURES!
[...truncated 48758 lines...]