Build: https://builds.apache.org/job/Lucene-Solr-repro/2609/
[...truncated 28 lines...] [repro] Jenkins log URL: https://builds.apache.org/job/Lucene-Solr-BadApples-Tests-master/251/consoleText [repro] Revision: a1c6e642aad90d3615b4c71bf261a5aad7e32369 [repro] Repro line: ant test -Dtestcase=BasicAuthIntegrationTest -Dtests.seed=C5143895DF8F38D5 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=ca-ES -Dtests.timezone=Etc/GMT+10 -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [repro] Repro line: ant test -Dtestcase=TestSimLargeCluster -Dtests.method=testAddNode -Dtests.seed=C5143895DF8F38D5 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=es-ES -Dtests.timezone=Africa/Kigali -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [repro] Repro line: ant test -Dtestcase=TestSimLargeCluster -Dtests.method=testNodeLost -Dtests.seed=C5143895DF8F38D5 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=es-ES -Dtests.timezone=Africa/Kigali -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [repro] Repro line: ant test -Dtestcase=TestSimTriggerIntegration -Dtests.method=testNodeLostTriggerRestoreState -Dtests.seed=C5143895DF8F38D5 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=lt-LT -Dtests.timezone=Europe/Moscow -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [repro] git rev-parse --abbrev-ref HEAD [repro] git rev-parse HEAD [repro] Initial local git branch/revision: e5fda5d6f1cc6010e6b3565aa4bd70be31621692 [repro] git fetch [repro] git checkout a1c6e642aad90d3615b4c71bf261a5aad7e32369 [...truncated 2 lines...] [repro] git merge --ff-only [...truncated 1 lines...] [repro] ant clean [...truncated 6 lines...] [repro] Test suites by module: [repro] solr/core [repro] TestSimTriggerIntegration [repro] TestSimLargeCluster [repro] BasicAuthIntegrationTest [repro] ant compile-test [...truncated 3592 lines...] [repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=15 -Dtests.class="*.TestSimTriggerIntegration|*.TestSimLargeCluster|*.BasicAuthIntegrationTest" -Dtests.showOutput=onerror -Dtests.seed=C5143895DF8F38D5 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=lt-LT -Dtests.timezone=Europe/Moscow -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [...truncated 26546 lines...] [junit4] 2> ERROR: Solr requires authentication for http://127.0.0.1:41794/solr/admin/info/system. Please supply valid credentials. HTTP code=401 [junit4] 2> [junit4] 2> 108708 ERROR (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[C5143895DF8F38D5]) [ ] o.a.s.s.BasicAuthIntegrationTest RunExampleTool failed due to: java.lang.NullPointerException; stdout from tool prior to failure: [junit4] 2> 108740 ERROR (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.s.i.CloudSolrClient Request to collection [authCollection] failed due to (401) org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:44082/solr/authCollection: Expected mime type application/octet-stream but got text/html. <html> [junit4] 2> <head> [junit4] 2> <meta http-equiv="Content-Type" content="text/html;charset=utf-8"/> [junit4] 2> <title>Error 401 require authentication</title> [junit4] 2> </head> [junit4] 2> <body><h2>HTTP ERROR 401</h2> [junit4] 2> <p>Problem accessing /solr/authCollection/select. Reason: [junit4] 2> <pre> require authentication</pre></p><hr><a href="http://eclipse.org/jetty";>Powered by Jetty:// 9.4.14.v20181114</a><hr/> [junit4] 2> [junit4] 2> </body> [junit4] 2> </html> [junit4] 2> , retry=0 commError=false errorCode=401 [junit4] 2> 108740 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems [junit4] 2> 108901 INFO (qtp1978291675-163) [n:127.0.0.1:41794_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/key params={omitHeader=true&wt=json} status=0 QTime=0 [junit4] 2> 108901 INFO (qtp1978291675-164) [n:127.0.0.1:41794_solr ] o.a.s.s.PKIAuthenticationPlugin New Key obtained from node: 127.0.0.1:41794_solr / MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAm/mF6Dp4EqxO0JbcGBLzUT3ztszIfWz9PZs+0sGeikpykRsZM/EoXz0kj4pRLepSfA8f3A+seWrhay0d7T41BZGMYVNv3GIJLGDka3c5WjlOQ+N3cQTTr79OQs0YQBaIXpGRgAabr5kd8n7waqC29p/Z+bjCRN/5GSGtaH4c31VEpl9f6CVseKdyGVIlX51E6LnaDY76yUk29SiDKCMmxNDn+593DM7yl2iwIjciQkTDCMrn09zdbCqSGu2TpH6BRcrRaDmJ9RbcO+t+vyd8Byq29xq2lIpuDBnTU7D1CxgR4JHcm2KS4cYhaGxKABEarhUz9WgO8PIGxpHlpeXhCwIDAQAB [junit4] 2> 108948 INFO (qtp89925652-152) [n:127.0.0.1:43122_solr c:authCollection s:shard3 r:core_node6 x:authCollection_shard3_replica_n3] o.a.s.c.S.Request [authCollection_shard3_replica_n3] webapp=/solr path=/select params={df=text&distrib=false&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&shard.url=http://127.0.0.1:43122/solr/authCollection_shard3_replica_n3/&rows=10&version=2&q=*:*&NOW=1546485305933&isShard=true&wt=javabin} hits=0 status=0 QTime=63 [junit4] 2> 108952 INFO (qtp342634739-295) [n:127.0.0.1:44082_solr c:authCollection s:shard1 r:core_node4 x:authCollection_shard1_replica_n1] o.a.s.c.S.Request [authCollection_shard1_replica_n1] webapp=/solr path=/select params={df=text&distrib=false&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&shard.url=http://127.0.0.1:44082/solr/authCollection_shard1_replica_n1/&rows=10&version=2&q=*:*&NOW=1546485305933&isShard=true&wt=javabin} hits=0 status=0 QTime=62 [junit4] 2> 108952 INFO (qtp1978291675-164) [n:127.0.0.1:41794_solr c:authCollection s:shard2 r:core_node5 x:authCollection_shard2_replica_n2] o.a.s.c.S.Request [authCollection_shard2_replica_n2] webapp=/solr path=/select params={df=text&distrib=false&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&shard.url=http://127.0.0.1:41794/solr/authCollection_shard2_replica_n2/&rows=10&version=2&q=*:*&NOW=1546485305933&isShard=true&wt=javabin} hits=1 status=0 QTime=49 [junit4] 2> 109012 INFO (qtp1978291675-165) [n:127.0.0.1:41794_solr c:authCollection s:shard2 r:core_node5 x:authCollection_shard2_replica_n2] o.a.s.c.S.Request [authCollection_shard2_replica_n2] webapp=/solr path=/select params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1546485305933&ids=4&isShard=true&shard.url=http://127.0.0.1:41794/solr/authCollection_shard2_replica_n2/&wt=javabin&version=2} status=0 QTime=3 [junit4] 2> 109014 INFO (qtp1978291675-166) [n:127.0.0.1:41794_solr c:authCollection s:shard2 r:core_node5 x:authCollection_shard2_replica_n2] o.a.s.c.S.Request [authCollection_shard2_replica_n2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=270 [junit4] 2> 109027 INFO (qtp89925652-158) [n:127.0.0.1:43122_solr c:authCollection s:shard3 r:core_node6 x:authCollection_shard3_replica_n3] o.a.s.u.p.LogUpdateProcessorFactory [authCollection_shard3_replica_n3] webapp=/solr path=/update params={wt=javabin&version=2}{add=[5 (1621607376449699840)]} 0 2 [junit4] 2> 109056 INFO (qtp89925652-155) [n:127.0.0.1:43122_solr c:authCollection s:shard3 r:core_node6 x:authCollection_shard3_replica_n3] o.a.s.u.p.LogUpdateProcessorFactory [authCollection_shard3_replica_n3] webapp=/solr path=/update params={_stateVer_=authCollection:9&wt=javabin&version=2}{add=[5 (1621607376476962816)]} 0 5 [junit4] 2> 109069 INFO (qtp1978291675-167) [n:127.0.0.1:41794_solr c:authCollection s:shard2 r:core_node5 x:authCollection_shard2_replica_n2] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1621607376494788608,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 109072 INFO (qtp342634739-296) [n:127.0.0.1:44082_solr c:authCollection s:shard1 r:core_node4 x:authCollection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1621607376497934336,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 109074 INFO (qtp342634739-296) [n:127.0.0.1:44082_solr c:authCollection s:shard1 r:core_node4 x:authCollection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 109074 INFO (qtp1978291675-167) [n:127.0.0.1:41794_solr c:authCollection s:shard2 r:core_node5 x:authCollection_shard2_replica_n2] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@41d3b91f commitCommandVersion:1621607376494788608 [junit4] 2> 109081 INFO (qtp1978291675-167) [n:127.0.0.1:41794_solr c:authCollection s:shard2 r:core_node5 x:authCollection_shard2_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@69e4be0e[authCollection_shard2_replica_n2] main] [junit4] 2> 109082 INFO (qtp1978291675-167) [n:127.0.0.1:41794_solr c:authCollection s:shard2 r:core_node5 x:authCollection_shard2_replica_n2] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 109083 INFO (searcherExecutor-122-thread-1-processing-n:127.0.0.1:41794_solr x:authCollection_shard2_replica_n2 c:authCollection s:shard2 r:core_node5) [n:127.0.0.1:41794_solr c:authCollection s:shard2 r:core_node5 x:authCollection_shard2_replica_n2] o.a.s.c.SolrCore [authCollection_shard2_replica_n2] Registered new searcher Searcher@69e4be0e[authCollection_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, mergeMaxNumSegments=-1, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=merge, mergeFactor=1, os.version=4.4.0-112-generic, timestamp=1546485305742}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))} [junit4] 2> 109086 INFO (qtp1978291675-167) [n:127.0.0.1:41794_solr c:authCollection s:shard2 r:core_node5 x:authCollection_shard2_replica_n2] o.a.s.u.p.LogUpdateProcessorFactory [authCollection_shard2_replica_n2] webapp=/solr path=/update params={update.distrib=TOLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:43122/solr/authCollection_shard3_replica_n3/&commit_end_point=leaders&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 17 [junit4] 2> 109098 INFO (qtp342634739-296) [n:127.0.0.1:44082_solr c:authCollection s:shard1 r:core_node4 x:authCollection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 109098 INFO (qtp342634739-296) [n:127.0.0.1:44082_solr c:authCollection s:shard1 r:core_node4 x:authCollection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [authCollection_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=TOLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:43122/solr/authCollection_shard3_replica_n3/&commit_end_point=leaders&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 26 [junit4] 2> 109099 INFO (qtp89925652-156) [n:127.0.0.1:43122_solr c:authCollection s:shard3 r:core_node6 x:authCollection_shard3_replica_n3] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1621607376526245888,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 109101 INFO (qtp89925652-156) [n:127.0.0.1:43122_solr c:authCollection s:shard3 r:core_node6 x:authCollection_shard3_replica_n3] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@4954ca55 commitCommandVersion:1621607376526245888 [junit4] 2> 109124 INFO (qtp89925652-156) [n:127.0.0.1:43122_solr c:authCollection s:shard3 r:core_node6 x:authCollection_shard3_replica_n3] o.a.s.s.SolrIndexSearcher Opening [Searcher@53cc4b50[authCollection_shard3_replica_n3] main] [junit4] 2> 109125 INFO (qtp89925652-156) [n:127.0.0.1:43122_solr c:authCollection s:shard3 r:core_node6 x:authCollection_shard3_replica_n3] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 109126 INFO (searcherExecutor-120-thread-1-processing-n:127.0.0.1:43122_solr x:authCollection_shard3_replica_n3 c:authCollection s:shard3 r:core_node6) [n:127.0.0.1:43122_solr c:authCollection s:shard3 r:core_node6 x:authCollection_shard3_replica_n3] o.a.s.c.SolrCore [authCollection_shard3_replica_n3] Registered new searcher Searcher@53cc4b50[authCollection_shard3_replica_n3] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C2/1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1546485306295}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]:delGen=1)))} [junit4] 2> 109133 INFO (qtp89925652-156) [n:127.0.0.1:43122_solr c:authCollection s:shard3 r:core_node6 x:authCollection_shard3_replica_n3] o.a.s.u.p.LogUpdateProcessorFactory [authCollection_shard3_replica_n3] webapp=/solr path=/update params={_stateVer_=authCollection:9&commit=true&wt=javabin&version=2}{commit=} 0 72 [junit4] 2> 109162 INFO (qtp1978291675-164) [n:127.0.0.1:41794_solr c:authCollection s:shard2 r:core_node5 x:authCollection_shard2_replica_n2] o.a.s.c.S.Request [authCollection_shard2_replica_n2] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=authCollection:9&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&shard.url=http://127.0.0.1:41794/solr/authCollection_shard2_replica_n2/&rows=10&version=2&q=id:5&NOW=1546485306324&isShard=true&wt=javabin} hits=0 status=0 QTime=17 [junit4] 2> 109162 INFO (qtp342634739-297) [n:127.0.0.1:44082_solr c:authCollection s:shard1 r:core_node4 x:authCollection_shard1_replica_n1] o.a.s.c.S.Request [authCollection_shard1_replica_n1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=authCollection:9&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&shard.url=http://127.0.0.1:44082/solr/authCollection_shard1_replica_n1/&rows=10&version=2&q=id:5&NOW=1546485306324&isShard=true&wt=javabin} hits=0 status=0 QTime=11 [junit4] 2> 109165 INFO (qtp89925652-157) [n:127.0.0.1:43122_solr c:authCollection s:shard3 r:core_node6 x:authCollection_shard3_replica_n3] o.a.s.c.S.Request [authCollection_shard3_replica_n3] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=authCollection:9&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&shard.url=http://127.0.0.1:43122/solr/authCollection_shard3_replica_n3/&rows=10&version=2&q=id:5&NOW=1546485306324&isShard=true&wt=javabin} hits=1 status=0 QTime=15 [junit4] 2> 109181 INFO (qtp89925652-152) [n:127.0.0.1:43122_solr c:authCollection s:shard3 r:core_node6 x:authCollection_shard3_replica_n3] o.a.s.c.S.Request [authCollection_shard3_replica_n3] webapp=/solr path=/select params={q=id:5&df=text&distrib=false&_stateVer_=authCollection:9&shards.purpose=64&NOW=1546485306324&ids=5&isShard=true&shard.url=http://127.0.0.1:43122/solr/authCollection_shard3_replica_n3/&wt=javabin&version=2} status=0 QTime=1 [junit4] 2> 109183 INFO (qtp1978291675-163) [n:127.0.0.1:41794_solr c:authCollection s:shard2 r:core_node5 x:authCollection_shard2_replica_n2] o.a.s.c.S.Request [authCollection_shard2_replica_n2] webapp=/solr path=/select params={q=id:5&_stateVer_=authCollection:9&wt=javabin&version=2} hits=1 status=0 QTime=48 [junit4] 2> 109185 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[C5143895DF8F38D5]) [ ] o.a.s.s.BasicAuthIntegrationTest Added Basic Auth security Header aGFycnk6SGFycnlJc1ViZXJDb29s [junit4] 2> 109188 INFO (zkCallback-36-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 109188 INFO (zkCallback-36-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 109188 INFO (zkCallback-80-thread-3) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 109188 INFO (zkCallback-80-thread-3) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 109188 INFO (zkCallback-34-thread-3) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 109188 INFO (zkCallback-34-thread-3) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 109189 INFO (qtp1978291675-166) [n:127.0.0.1:41794_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/security/authentication params={} status=0 QTime=3 [junit4] 2> 109189 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[C5143895DF8F38D5]) [ ] o.a.s.s.BasicAuthIntegrationTest Added Basic Auth security Header aGFycnk6SGFycnlJc1ViZXJDb29s [junit4] 2> 109190 INFO (qtp1978291675-165) [n:127.0.0.1:41794_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/security/authentication params={} status=0 QTime=0 [junit4] 2> 109247 INFO (qtp1978291675-163) [n:127.0.0.1:41794_solr c:authCollection s:shard2 r:core_node5 x:authCollection_shard2_replica_n2] o.a.s.c.S.Request [authCollection_shard2_replica_n2] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=authCollection:9&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&shard.url=http://127.0.0.1:41794/solr/authCollection_shard2_replica_n2/&rows=10&version=2&q=id:5&NOW=1546485306381&isShard=true&wt=javabin} hits=0 status=0 QTime=0 [junit4] 2> 109262 INFO (qtp89925652-157) [n:127.0.0.1:43122_solr c:authCollection s:shard3 r:core_node6 x:authCollection_shard3_replica_n3] o.a.s.c.S.Request [authCollection_shard3_replica_n3] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=authCollection:9&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&shard.url=http://127.0.0.1:43122/solr/authCollection_shard3_replica_n3/&rows=10&version=2&q=id:5&NOW=1546485306381&isShard=true&wt=javabin} hits=1 status=0 QTime=1 [junit4] 2> 109278 INFO (qtp342634739-295) [n:127.0.0.1:44082_solr c:authCollection s:shard1 r:core_node4 x:authCollection_shard1_replica_n1] o.a.s.c.S.Request [authCollection_shard1_replica_n1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=authCollection:9&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&shard.url=http://127.0.0.1:44082/solr/authCollection_shard1_replica_n1/&rows=10&version=2&q=id:5&NOW=1546485306381&isShard=true&wt=javabin} hits=0 status=0 QTime=0 [junit4] 2> 109293 INFO (qtp89925652-152) [n:127.0.0.1:43122_solr c:authCollection s:shard3 r:core_node6 x:authCollection_shard3_replica_n3] o.a.s.c.S.Request [authCollection_shard3_replica_n3] webapp=/solr path=/select params={q=id:5&df=text&distrib=false&_stateVer_=authCollection:9&shards.purpose=64&NOW=1546485306381&ids=5&isShard=true&shard.url=http://127.0.0.1:43122/solr/authCollection_shard3_replica_n3/&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 109295 INFO (qtp89925652-158) [n:127.0.0.1:43122_solr c:authCollection s:shard3 r:core_node6 x:authCollection_shard3_replica_n3] o.a.s.c.S.Request [authCollection_shard3_replica_n3] webapp=/solr path=/select params={q=id:5&_stateVer_=authCollection:9&wt=javabin&version=2} hits=1 status=0 QTime=103 [junit4] 2> 109296 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[C5143895DF8F38D5]) [ ] o.a.s.s.BasicAuthIntegrationTest Added Basic Auth security Header aGFycnk6SGFycnlJc1ViZXJDb29s [junit4] 2> 109299 INFO (zkCallback-34-thread-3) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 109299 INFO (zkCallback-34-thread-3) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 109300 INFO (qtp1978291675-166) [n:127.0.0.1:41794_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/security/authentication params={} status=0 QTime=2 [junit4] 2> 109303 INFO (zkCallback-80-thread-3) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 109303 INFO (zkCallback-36-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 109303 INFO (zkCallback-80-thread-3) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 109303 INFO (zkCallback-36-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 109314 INFO (jetty-closer-111-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=957815642 [junit4] 2> 109314 INFO (jetty-closer-111-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:44082_solr [junit4] 2> 109315 INFO (jetty-closer-111-thread-1) [ ] o.a.s.c.CoreContainer Publish this node as DOWN... [junit4] 2> 109315 INFO (jetty-closer-111-thread-1) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:44082_solr as DOWN [junit4] 2> 109318 INFO (zkCallback-34-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 109318 INFO (zkCallback-34-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 109318 INFO (zkCallback-34-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 109318 INFO (zkCallback-80-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 109318 INFO (jetty-closer-111-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1942077191 [junit4] 2> 109318 INFO (jetty-closer-111-thread-2) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:41794_solr [junit4] 2> 109318 INFO (zkCallback-36-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 109318 INFO (zkCallback-36-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 109322 INFO (jetty-closer-111-thread-2) [ ] o.a.s.c.CoreContainer Publish this node as DOWN... [junit4] 2> 109322 INFO (jetty-closer-111-thread-2) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:41794_solr as DOWN [junit4] 2> 109322 INFO (zkCallback-80-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 109322 INFO (zkCallback-80-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 109322 INFO (zkCallback-80-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 109322 INFO (jetty-closer-111-thread-3) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=2012478556 [junit4] 2> 109322 INFO (jetty-closer-111-thread-3) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:43122_solr [junit4] 2> 109324 INFO (jetty-closer-111-thread-3) [ ] o.a.s.c.CoreContainer Publish this node as DOWN... [junit4] 2> 109324 INFO (jetty-closer-111-thread-3) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:43122_solr as DOWN [junit4] 2> 109346 INFO (coreCloseExecutor-142-thread-1) [n:127.0.0.1:41794_solr c:authCollection s:shard2 r:core_node5 x:authCollection_shard2_replica_n2] o.a.s.c.SolrCore [authCollection_shard2_replica_n2] CLOSING SolrCore org.apache.solr.core.SolrCore@8ca5a85 [junit4] 2> 109346 INFO (coreCloseExecutor-142-thread-1) [n:127.0.0.1:41794_solr c:authCollection s:shard2 r:core_node5 x:authCollection_shard2_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.authCollection.shard2.replica_n2, tag=8ca5a85 [junit4] 2> 109346 INFO (coreCloseExecutor-142-thread-1) [n:127.0.0.1:41794_solr c:authCollection s:shard2 r:core_node5 x:authCollection_shard2_replica_n2] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@490af688: rootName = solr_41794, domain = solr.core.authCollection.shard2.replica_n2, service url = null, agent id = null] for registry solr.core.authCollection.shard2.replica_n2 / com.codahale.metrics.MetricRegistry@7b2cd92 [junit4] 2> 109361 INFO (coreCloseExecutor-143-thread-1) [n:127.0.0.1:44082_solr c:authCollection s:shard1 r:core_node4 x:authCollection_shard1_replica_n1] o.a.s.c.SolrCore [authCollection_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@d471726 [junit4] 2> 109361 INFO (coreCloseExecutor-143-thread-1) [n:127.0.0.1:44082_solr c:authCollection s:shard1 r:core_node4 x:authCollection_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.authCollection.shard1.replica_n1, tag=d471726 [junit4] 2> 109361 INFO (coreCloseExecutor-143-thread-1) [n:127.0.0.1:44082_solr c:authCollection s:shard1 r:core_node4 x:authCollection_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@79c7623f: rootName = solr_44082, domain = solr.core.authCollection.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.authCollection.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@19fd11fc [junit4] 2> 109374 INFO (coreCloseExecutor-142-thread-1) [n:127.0.0.1:41794_solr c:authCollection s:shard2 r:core_node5 x:authCollection_shard2_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.authCollection.shard2.leader, tag=8ca5a85 [junit4] 2> 109375 INFO (coreCloseExecutor-144-thread-1) [n:127.0.0.1:43122_solr c:authCollection s:shard3 r:core_node6 x:authCollection_shard3_replica_n3] o.a.s.c.SolrCore [authCollection_shard3_replica_n3] CLOSING SolrCore org.apache.solr.core.SolrCore@16e4f839 [junit4] 2> 109375 INFO (coreCloseExecutor-144-thread-1) [n:127.0.0.1:43122_solr c:authCollection s:shard3 r:core_node6 x:authCollection_shard3_replica_n3] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.authCollection.shard3.replica_n3, tag=16e4f839 [junit4] 2> 109375 INFO (coreCloseExecutor-144-thread-1) [n:127.0.0.1:43122_solr c:authCollection s:shard3 r:core_node6 x:authCollection_shard3_replica_n3] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6a5f9eac: rootName = solr_43122, domain = solr.core.authCollection.shard3.replica_n3, service url = null, agent id = null] for registry solr.core.authCollection.shard3.replica_n3 / com.codahale.metrics.MetricRegistry@12de447f [junit4] 2> 109395 INFO (jetty-closer-111-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 109395 INFO (coreCloseExecutor-144-thread-1) [n:127.0.0.1:43122_solr c:authCollection s:shard3 r:core_node6 x:authCollection_shard3_replica_n3] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.authCollection.shard3.leader, tag=16e4f839 [junit4] 2> 109404 INFO (jetty-closer-111-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@24cc4950: rootName = solr_41794, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@78e75b9d [junit4] 2> 109406 INFO (coreCloseExecutor-143-thread-1) [n:127.0.0.1:44082_solr c:authCollection s:shard1 r:core_node4 x:authCollection_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.authCollection.shard1.leader, tag=d471726 [junit4] 2> 109409 INFO (jetty-closer-111-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 109409 INFO (jetty-closer-111-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6b7334b5: rootName = solr_41794, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@6b13a49f [junit4] 2> 109416 INFO (jetty-closer-111-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 109416 INFO (jetty-closer-111-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4554a69e: rootName = solr_41794, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@3a5ad1b8 [junit4] 2> 109416 INFO (jetty-closer-111-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 109442 INFO (zkCallback-36-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 109442 INFO (zkCallback-34-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 109442 INFO (zkCallback-36-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 109442 INFO (zkCallback-34-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 109442 INFO (zkCallback-34-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 109443 INFO (zkCallback-80-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 109443 INFO (zkCallback-80-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 109443 INFO (zkCallback-80-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 109458 INFO (jetty-closer-111-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 109459 INFO (jetty-closer-111-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@23a38ff8: rootName = solr_44082, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@54a20fc4 [junit4] 2> 109459 INFO (zkCallback-80-thread-4) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 109463 INFO (jetty-closer-111-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 109463 INFO (jetty-closer-111-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@8467389: rootName = solr_44082, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@6b13a49f [junit4] 2> 109466 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x106b5f690b5000e, likely client has closed socket [junit4] 2> 109470 INFO (jetty-closer-111-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 109471 INFO (jetty-closer-111-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@28b03610: rootName = solr_43122, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@76b3d38a [junit4] 2> 109473 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x106b5f690b5000a, likely client has closed socket [junit4] 2> 109473 INFO (zkCallback-87-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 109473 INFO (zkCallback-49-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 109474 INFO (zkCallback-36-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 109476 INFO (jetty-closer-111-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 109476 INFO (jetty-closer-111-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@147b076f: rootName = solr_44082, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@3a5ad1b8 [junit4] 2> 109477 INFO (jetty-closer-111-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 109483 INFO (jetty-closer-111-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 109483 INFO (jetty-closer-111-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3fcb5083: rootName = solr_43122, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@6b13a49f [junit4] 2> 109485 INFO (jetty-closer-111-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 109485 INFO (jetty-closer-111-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6da924e: rootName = solr_43122, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@3a5ad1b8 [junit4] 2> 109485 INFO (jetty-closer-111-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 109488 INFO (closeThreadPool-119-thread-2) [ ] o.a.s.c.Overseer Overseer (id=73946514492555273-127.0.0.1:43122_solr-n_0000000000) closing [junit4] 1> Done close org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@4c630220[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 7] [junit4] 2> 109566 INFO (OverseerStateUpdate-73946514492555273-127.0.0.1:43122_solr-n_0000000000) [n:127.0.0.1:43122_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:43122_solr [junit4] 1> Done close org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@703e07f5[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 10] [junit4] 2> 109571 INFO (zkCallback-80-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 109572 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x106b5f690b50009, likely client has closed socket [junit4] 2> 109573 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x106b5f690b50013, likely client has closed socket [junit4] 2> 109573 INFO (zkCallback-80-thread-4) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:44082_solr [junit4] 1> Done close org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@3b2ec636[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1] [junit4] 2> 109589 INFO (OverseerAutoScalingTriggerThread-73946514492555273-127.0.0.1:43122_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 1> Done close org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@63c24f83[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1] [junit4] 2> 109630 INFO (jetty-closer-111-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@7e4de116{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:0} [junit4] 2> 109647 INFO (jetty-closer-111-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5b70ba29{/solr,null,UNAVAILABLE} [junit4] 2> 109653 INFO (jetty-closer-111-thread-2) [ ] o.e.j.s.session node0 Stopped scavenging [junit4] 2> 109654 INFO (jetty-closer-111-thread-3) [ ] o.a.s.c.Overseer Overseer (id=73946514492555273-127.0.0.1:43122_solr-n_0000000000) closing [junit4] 2> 109654 INFO (closeThreadPool-119-thread-1) [ ] o.a.s.c.Overseer Overseer (id=73946514492555273-127.0.0.1:43122_solr-n_0000000000) closing [junit4] 1> Done close org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@1a8e9f9b[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 10] [junit4] 2> 109662 INFO (jetty-closer-111-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@30af1ded{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:44082} [junit4] 2> 109666 INFO (jetty-closer-111-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4d203663{/solr,null,UNAVAILABLE} [junit4] 2> 109666 INFO (jetty-closer-111-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging [junit4] 1> Done close org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@65e64282[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 7] [junit4] 2> 109669 INFO (jetty-closer-111-thread-3) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@26fad93f{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:0} [junit4] 2> 109674 INFO (jetty-closer-111-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@3b10161c{/solr,null,UNAVAILABLE} [junit4] 2> 109674 INFO (jetty-closer-111-thread-3) [ ] o.e.j.s.session node0 Stopped scavenging [junit4] 2> 109676 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer. [junit4] 2> 109679 WARN (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 11 /solr/aliases.json [junit4] 2> 11 /solr/clusterprops.json [junit4] 2> 5 /solr/security.json [junit4] 2> 4 /solr/configs/conf [junit4] 2> 4 /solr/collections/authCollection/terms/shard1 [junit4] 2> 3 /solr/collections/authCollection/terms/shard2 [junit4] 2> 3 /solr/collections/authCollection/terms/shard3 [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 50 /solr/collections/authCollection/state.json [junit4] 2> 11 /solr/clusterstate.json [junit4] 2> 2 /solr/overseer_elect/election/73946514492555274-127.0.0.1:41794_solr-n_0000000001 [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 11 /solr/collections [junit4] 2> 10 /solr/live_nodes [junit4] 2> [junit4] 2> 109699 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:42601 [junit4] 2> 109699 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 42601 [junit4] 2> 109700 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[C5143895DF8F38D5]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testBasicAuth [junit4] OK 70.5s J2 | BasicAuthIntegrationTest.testBasicAuth [junit4] 2> 109701 INFO (SUITE-BasicAuthIntegrationTest-seed#[C5143895DF8F38D5]-worker) [ ] o.a.s.SolrTestCaseJ4 Waiting for all tracked resources to be released [junit4] 2> 119706 INFO (SUITE-BasicAuthIntegrationTest-seed#[C5143895DF8F38D5]-worker) [ ] o.a.s.SolrTestCaseJ4 Waiting for all tracked resources to be released [junit4] 2> 129709 INFO (SUITE-BasicAuthIntegrationTest-seed#[C5143895DF8F38D5]-worker) [ ] o.a.s.SolrTestCaseJ4 Waiting for all tracked resources to be released [junit4] 2> SUITE-BasicAuthIntegrationTest-seed#[C5143895DF8F38D5]: [junit4] 2> java.lang.Thread.sleep(Native Method) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> [junit4] 2> Connection evictor: [junit4] 2> java.lang.Thread.sleep(Native Method) [junit4] 2> org.apache.http.impl.client.IdleConnectionEvictor$1.run(IdleConnectionEvictor.java:66) [junit4] 2> java.lang.Thread.run(Thread.java:748) [junit4] 2> [junit4] 2> JUnit4-serializer-daemon: [junit4] 2> java.lang.Thread.sleep(Native Method) [junit4] 2> com.carrotsearch.ant.tasks.junit4.events.Serializer$1.run(Serializer.java:50) [junit4] 2> [junit4] 2> SUITE-BasicAuthIntegrationTest-seed#[C5143895DF8F38D5]-worker: [junit4] 2> java.lang.Thread.dumpThreads(Native Method) [junit4] 2> java.lang.Thread.getAllStackTraces(Thread.java:1610) [junit4] 2> org.apache.solr.SolrTestCaseJ4.clearObjectTrackerAndCheckEmpty(SolrTestCaseJ4.java:391) [junit4] 2> org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:318) [junit4] 2> [...sun.*, java.lang.reflect.*, com.carrotsearch.randomizedtesting.*] [junit4] 2> org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) [junit4] 2> org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) [junit4] 2> org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) [junit4] 2> org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> java.lang.Thread.run(Thread.java:748) [junit4] 2> [junit4] 2> Reference Handler: [junit4] 2> java.lang.Object.wait(Native Method) [junit4] 2> java.lang.Object.wait(Object.java:502) [junit4] 2> java.lang.ref.Reference.tryHandlePending(Reference.java:191) [junit4] 2> java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153) [junit4] 2> [junit4] 2> Finalizer: [junit4] 2> java.lang.Object.wait(Native Method) [junit4] 2> java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144) [junit4] 2> java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165) [junit4] 2> java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216) [junit4] 2> [junit4] 2> main: [junit4] 2> java.lang.Object.wait(Native Method) [junit4] 2> java.lang.Thread.join(Thread.java:1252) [junit4] 2> java.lang.Thread.join(Thread.java:1326) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMain.execute(SlaveMain.java:269) [junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMain.main(SlaveMain.java:394) [junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe.main(SlaveMainSafe.java:13) [junit4] 2> [junit4] 2> Signal Dispatcher: [junit4] 2> [junit4] 2> 139712 INFO (SUITE-BasicAuthIntegrationTest-seed#[C5143895DF8F38D5]-worker) [ ] o.a.s.SolrTestCaseJ4 Waiting for all tracked resources to be released [junit4] 2> SUITE-BasicAuthIntegrationTest-seed#[C5143895DF8F38D5]: [junit4] 2> java.lang.Thread.sleep(Native Method) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> [junit4] 2> Connection evictor: [junit4] 2> java.lang.Thread.sleep(Native Method) [junit4] 2> org.apache.http.impl.client.IdleConnectionEvictor$1.run(IdleConnectionEvictor.java:66) [junit4] 2> java.lang.Thread.run(Thread.java:748) [junit4] 2> [junit4] 2> JUnit4-serializer-daemon: [junit4] 2> java.lang.Thread.sleep(Native Method) [junit4] 2> com.carrotsearch.ant.tasks.junit4.events.Serializer$1.run(Serializer.java:50) [junit4] 2> [junit4] 2> SUITE-BasicAuthIntegrationTest-seed#[C5143895DF8F38D5]-worker: [junit4] 2> java.lang.Thread.dumpThreads(Native Method) [junit4] 2> java.lang.Thread.getAllStackTraces(Thread.java:1610) [junit4] 2> org.apache.solr.SolrTestCaseJ4.clearObjectTrackerAndCheckEmpty(SolrTestCaseJ4.java:391) [junit4] 2> org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:318) [junit4] 2> [...sun.*, java.lang.reflect.*, com.carrotsearch.randomizedtesting.*] [junit4] 2> org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) [junit4] 2> org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) [junit4] 2> org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) [junit4] 2> org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> java.lang.Thread.run(Thread.java:748) [junit4] 2> [junit4] 2> Reference Handler: [junit4] 2> java.lang.Object.wait(Native Method) [junit4] 2> java.lang.Object.wait(Object.java:502) [junit4] 2> java.lang.ref.Reference.tryHandlePending(Reference.java:191) [junit4] 2> java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153) [junit4] 2> [junit4] 2> Finalizer: [junit4] 2> java.lang.Object.wait(Native Method) [junit4] 2> java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144) [junit4] 2> java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165) [junit4] 2> java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216) [junit4] 2> [junit4] 2> main: [junit4] 2> java.lang.Object.wait(Native Method) [junit4] 2> java.lang.Thread.join(Thread.java:1252) [junit4] 2> java.lang.Thread.join(Thread.java:1326) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMain.execute(SlaveMain.java:269) [junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMain.main(SlaveMain.java:394) [junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe.main(SlaveMainSafe.java:13) [junit4] 2> [junit4] 2> Signal Dispatcher: [junit4] 2> [junit4] 2> 149715 INFO (SUITE-BasicAuthIntegrationTest-seed#[C5143895DF8F38D5]-worker) [ ] o.a.s.SolrTestCaseJ4 Waiting for all tracked resources to be released [junit4] 2> SUITE-BasicAuthIntegrationTest-seed#[C5143895DF8F38D5]: [junit4] 2> java.lang.Thread.sleep(Native Method) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> [junit4] 2> Connection evictor: [junit4] 2> java.lang.Thread.sleep(Native Method) [junit4] 2> org.apache.http.impl.client.IdleConnectionEvictor$1.run(IdleConnectionEvictor.java:66) [junit4] 2> java.lang.Thread.run(Thread.java:748) [junit4] 2> [junit4] 2> JUnit4-serializer-daemon: [junit4] 2> java.lang.Thread.sleep(Native Method) [junit4] 2> com.carrotsearch.ant.tasks.junit4.events.Serializer$1.run(Serializer.java:50) [junit4] 2> [junit4] 2> SUITE-BasicAuthIntegrationTest-seed#[C5143895DF8F38D5]-worker: [junit4] 2> java.lang.Thread.dumpThreads(Native Method) [junit4] 2> java.lang.Thread.getAllStackTraces(Thread.java:1610) [junit4] 2> org.apache.solr.SolrTestCaseJ4.clearObjectTrackerAndCheckEmpty(SolrTestCaseJ4.java:391) [junit4] 2> org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:318) [junit4] 2> [...sun.*, java.lang.reflect.*, com.carrotsearch.randomizedtesting.*] [junit4] 2> org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) [junit4] 2> org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) [junit4] 2> org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) [junit4] 2> org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> java.lang.Thread.run(Thread.java:748) [junit4] 2> [junit4] 2> Reference Handler: [junit4] 2> java.lang.Object.wait(Native Method) [junit4] 2> java.lang.Object.wait(Object.java:502) [junit4] 2> java.lang.ref.Reference.tryHandlePending(Reference.java:191) [junit4] 2> java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153) [junit4] 2> [junit4] 2> Finalizer: [junit4] 2> java.lang.Object.wait(Native Method) [junit4] 2> java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144) [junit4] 2> java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165) [junit4] 2> java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216) [junit4] 2> [junit4] 2> main: [junit4] 2> java.lang.Object.wait(Native Method) [junit4] 2> java.lang.Thread.join(Thread.java:1252) [junit4] 2> java.lang.Thread.join(Thread.java:1326) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMain.execute(SlaveMain.java:269) [junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMain.main(SlaveMain.java:394) [junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe.main(SlaveMainSafe.java:13) [junit4] 2> [junit4] 2> Signal Dispatcher: [junit4] 2> [junit4] 2> 159717 INFO (SUITE-BasicAuthIntegrationTest-seed#[C5143895DF8F38D5]-worker) [ ] o.a.s.SolrTestCaseJ4 Waiting for all tracked resources to be released [junit4] 2> SUITE-BasicAuthIntegrationTest-seed#[C5143895DF8F38D5]: [junit4] 2> java.lang.Thread.sleep(Native Method) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> [junit4] 2> Connection evictor: [junit4] 2> java.lang.Thread.sleep(Native Method) [junit4] 2> org.apache.http.impl.client.IdleConnectionEvictor$1.run(IdleConnectionEvictor.java:66) [junit4] 2> java.lang.Thread.run(Thread.java:748) [junit4] 2> [junit4] 2> JUnit4-serializer-daemon: [junit4] 2> java.lang.Thread.sleep(Native Method) [junit4] 2> com.carrotsearch.ant.tasks.junit4.events.Serializer$1.run(Serializer.java:50) [junit4] 2> [junit4] 2> SUITE-BasicAuthIntegrationTest-seed#[C5143895DF8F38D5]-worker: [junit4] 2> java.lang.Thread.dumpThreads(Native Method) [junit4] 2> java.lang.Thread.getAllStackTraces(Thread.java:1610) [junit4] 2> org.apache.solr.SolrTestCaseJ4.clearObjectTrackerAndCheckEmpty(SolrTestCaseJ4.java:391) [junit4] 2> org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:318) [junit4] 2> [...sun.*, java.lang.reflect.*, com.carrotsearch.randomizedtesting.*] [junit4] 2> org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) [junit4] 2> org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) [junit4] 2> org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) [junit4] 2> org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> java.lang.Thread.run(Thread.java:748) [junit4] 2> [junit4] 2> Reference Handler: [junit4] 2> java.lang.Object.wait(Native Method) [junit4] 2> java.lang.Object.wait(Object.java:502) [junit4] 2> java.lang.ref.Reference.tryHandlePending(Reference.java:191) [junit4] 2> java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153) [junit4] 2> [junit4] 2> Finalizer: [junit4] 2> java.lang.Object.wait(Native Method) [junit4] 2> java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144) [junit4] 2> java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165) [junit4] 2> java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216) [junit4] 2> [junit4] 2> main: [junit4] 2> java.lang.Object.wait(Native Method) [junit4] 2> java.lang.Thread.join(Thread.java:1252) [junit4] 2> java.lang.Thread.join(Thread.java:1326) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMain.execute(SlaveMain.java:269) [junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMain.main(SlaveMain.java:394) [junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe.main(SlaveMainSafe.java:13) [junit4] 2> [junit4] 2> Signal Dispatcher: [junit4] 2> [junit4] 2> 169720 INFO (SUITE-BasicAuthIntegrationTest-seed#[C5143895DF8F38D5]-worker) [ ] o.a.s.SolrTestCaseJ4 Waiting for all tracked resources to be released [junit4] 2> SUITE-BasicAuthIntegrationTest-seed#[C5143895DF8F38D5]: [junit4] 2> java.lang.Thread.sleep(Native Method) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> [junit4] 2> Connection evictor: [junit4] 2> java.lang.Thread.sleep(Native Method) [junit4] 2> org.apache.http.impl.client.IdleConnectionEvictor$1.run(IdleConnectionEvictor.java:66) [junit4] 2> java.lang.Thread.run(Thread.java:748) [junit4] 2> [junit4] 2> JUnit4-serializer-daemon: [junit4] 2> java.lang.Thread.sleep(Native Method) [junit4] 2> com.carrotsearch.ant.tasks.junit4.events.Serializer$1.run(Serializer.java:50) [junit4] 2> [junit4] 2> SUITE-BasicAuthIntegrationTest-seed#[C5143895DF8F38D5]-worker: [junit4] 2> java.lang.Thread.dumpThreads(Native Method) [junit4] 2> java.lang.Thread.getAllStackTraces(Thread.java:1610) [junit4] 2> org.apache.solr.SolrTestCaseJ4.clearObjectTrackerAndCheckEmpty(SolrTestCaseJ4.java:391) [junit4] 2> org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:318) [junit4] 2> [...sun.*, java.lang.reflect.*, com.carrotsearch.randomizedtesting.*] [junit4] 2> org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) [junit4] 2> org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) [junit4] 2> org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) [junit4] 2> org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> java.lang.Thread.run(Thread.java:748) [junit4] 2> [junit4] 2> Reference Handler: [junit4] 2> java.lang.Object.wait(Native Method) [junit4] 2> java.lang.Object.wait(Object.java:502) [junit4] 2> java.lang.ref.Reference.tryHandlePending(Reference.java:191) [junit4] 2> java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153) [junit4] 2> [junit4] 2> Finalizer: [junit4] 2> java.lang.Object.wait(Native Method) [junit4] 2> java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144) [junit4] 2> java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165) [junit4] 2> java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216) [junit4] 2> [junit4] 2> main: [junit4] 2> java.lang.Object.wait(Native Method) [junit4] 2> java.lang.Thread.join(Thread.java:1252) [junit4] 2> java.lang.Thread.join(Thread.java:1326) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMain.execute(SlaveMain.java:269) [junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMain.main(SlaveMain.java:394) [junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe.main(SlaveMainSafe.java:13) [junit4] 2> [junit4] 2> Signal Dispatcher: [junit4] 2> [junit4] 2> 170721 INFO (SUITE-BasicAuthIntegrationTest-seed#[C5143895DF8F38D5]-worker) [ ] o.a.s.SolrTestCaseJ4 ------------------------------------------------------- Done waiting for tracked resources to be released [junit4] 2> NOTE: test params are: codec=Asserting(Lucene80): {_root_=PostingsFormat(name=LuceneVarGapDocFreqInterval), id=FST50}, docValues:{_version_=DocValuesFormat(name=Lucene70), _root_=DocValuesFormat(name=Lucene70), id=DocValuesFormat(name=Lucene70)}, maxPointsInLeafNode=1134, maxMBSortInHeap=5.532379947129637, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@56452eec), locale=lt-LT, timezone=Europe/Moscow [junit4] 2> NOTE: Linux 4.4.0-112-generic amd64/Oracle Corporation 1.8.0_191 (64-bit)/cpus=4,threads=2,free=119858472,total=296747008 [junit4] 2> NOTE: All tests run in this JVM: [TestSimTriggerIntegration, BasicAuthIntegrationTest] [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicAuthIntegrationTest -Dtests.seed=C5143895DF8F38D5 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=lt-LT -Dtests.timezone=Europe/Moscow -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [junit4] ERROR 0.00s J2 | BasicAuthIntegrationTest (suite) <<< [junit4] > Throwable #1: java.lang.AssertionError: ObjectTracker found 1 object(s) that were not released!!! [InternalHttpClient] [junit4] > org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.http.impl.client.InternalHttpClient [junit4] > at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) [junit4] > at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:321) [junit4] > at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:330) [junit4] > at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:268) [junit4] > at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:255) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.<init>(HttpSolrClient.java:201) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient$Builder.build(HttpSolrClient.java:964) [junit4] > at org.apache.solr.client.solrj.embedded.JettySolrRunner.newClient(JettySolrRunner.java:751) [junit4] > at org.apache.solr.security.BasicAuthIntegrationTest.testBasicAuth(BasicAuthIntegrationTest.java:247) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > expected null, but was:<ObjectTracker found 1 object(s) that were not released!!! [InternalHttpClient] [junit4] > org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.http.impl.client.InternalHttpClient [junit4] > at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) [junit4] > at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:321) [junit4] > at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:330) [junit4] > at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:268) [junit4] > at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:255) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.<init>(HttpSolrClient.java:201) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient$Builder.build(HttpSolrClient.java:964) [junit4] > at org.apache.solr.client.solrj.embedded.JettySolrRunner.newClient(JettySolrRunner.java:751) [junit4] > at org.apache.solr.security.BasicAuthIntegrationTest.testBasicAuth(BasicAuthIntegrationTest.java:247) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > > [junit4] > at __randomizedtesting.SeedInfo.seed([C5143895DF8F38D5]:0) [junit4] > at org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:319) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] Completed [4/15 (4!)] on J2 in 132.24s, 1 test, 1 failure <<< FAILURES! [junit4] [junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestSimTriggerIntegration [junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-repro/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestSimTriggerIntegration_C5143895DF8F38D5-002/init-core-data-001 [junit4] 2> 170854 WARN (SUITE-TestSimTriggerIntegration-seed#[C5143895DF8F38D5]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=13 numCloses=13 [junit4] 2> 170854 INFO (SUITE-TestSimTriggerIntegration-seed#[C5143895DF8F38D5]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true [junit4] 2> 170856 INFO (SUITE-TestSimTriggerIntegration-seed#[C5143895DF8F38D5]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN) [junit4] 2> 170856 INFO (SUITE-TestSimTriggerIntegration-seed#[C5143895DF8F38D5]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom [junit4] 2> 170863 INFO (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[C5143895DF8F38D5]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTriggerRestoreState [junit4] 2> 170869 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10028_solr [junit4] 2> 170869 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers [junit4] 2> 170870 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1 [junit4] 2> 170870 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0 [junit4] 2> 170870 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1 [junit4] 2> 170904 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=0 [junit4] 2> 170904 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 0 [junit4] 2> 170904 INFO (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[C5143895DF8F38D5]) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory. [junit4] 2> 170934 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10029_solr, 127.0.0.1:10028_solr] [junit4] 2> 170937 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- cleaning old nodeLost / nodeAdded markers [junit4] 2> 170937 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1 [junit4] 2> 170938 DEBUG (simCloudManagerPool-149-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 170938 DEBUG (simCloudManagerPool-149-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2 [junit4] 2> 170942 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2 [junit4] 2> 170943 DEBUG (ScheduledTrigger-150-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2 [junit4] 2> 170943 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- cleaning old nodeLost / nodeAdded markers [junit4] 2> 170943 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2 [junit4] 2> 170944 DEBUG (simCloudManagerPool-149-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 170945 DEBUG (simCloudManagerPool-149-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3 [junit4] 2> 170946 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3 [junit4] 2> 170946 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestSimTriggerIntegration TestTriggerAction init [junit4] 2> 170946 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger node_lost_restore_trigger - Initial livenodes: [127.0.0.1:10029_solr, 127.0.0.1:10030_solr, 127.0.0.1:10028_solr] [junit4] 2> 170946 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- cleaning old nodeLost / nodeAdded markers [junit4] 2> 170946 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3 [junit4] 2> 170946 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- created marker: /autoscaling/nodeLost/127.0.0.1:10030_solr [junit4] 2> 170947 DEBUG (ScheduledTrigger-150-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_restore_trigger with currently live nodes: 2 and last live nodes: 3 [junit4] 2> 170947 DEBUG (ScheduledTrigger-150-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10030_solr [junit4] 2> 170963 DEBUG (ScheduledTrigger-150-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2 [junit4] 2> 170967 DEBUG (ScheduledTrigger-150-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_restore_trigger with currently live nodes: 2 and last live nodes: 2 [junit4] 2> 170978 DEBUG (simCloudManagerPool-149-thread-4) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 170978 DEBUG (simCloudManagerPool-149-thread-4) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4 [junit4] 2> 170978 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4 [junit4] 2> 170979 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestSimTriggerIntegration TestTriggerAction init [junit4] 2> 170979 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger node_lost_restore_trigger - Initial livenodes: [127.0.0.1:10029_solr, 127.0.0.1:10028_solr] [junit4] 2> 170979 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- cleaning old nodeLost / nodeAdded markers [junit4] 2> 170979 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4 [junit4] 2> 170979 DEBUG (ScheduledTrigger-150-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_restore_trigger with currently live nodes: 2 and last live nodes: 2 [junit4] 2> 170979 DEBUG (ScheduledTrigger-150-thread-1) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10030_solr] [junit4] 2> 170979 DEBUG (ScheduledTrigger-150-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"666cbe101f337eTbluweyejjslpxfyk4vqegzwde", [junit4] 2> "source":"node_lost_restore_trigger", [junit4] 2> "eventTime":28830011194553214, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[28830011194553214], [junit4] 2> "preferredOperation":"movereplica", [junit4] 2> "nodeNames":["127.0.0.1:10030_solr"]}} [junit4] 2> 170980 DEBUG (ScheduledTrigger-150-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_lost_restore_trigger] [junit4] 2> 170980 DEBUG (ScheduledTrigger-150-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event { [junit4] 2> "id":"666cbe101f337eTbluweyejjslpxfyk4vqegzwde", [junit4] 2> "source":"node_lost_restore_trigger", [junit4] 2> "eventTime":28830011194553214, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[28830011194553214], [junit4] 2> "preferredOperation":"movereplica", [junit4] 2> "_enqueue_time_":28830012848303864, [junit4] 2> "nodeNames":["127.0.0.1:10030_solr"]}} [junit4] 2> 170980 DEBUG (AutoscalingActionExecutor-151-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"666cbe101f337eTbluweyejjslpxfyk4vqegzwde", [junit4] 2> "source":"node_lost_restore_trigger", [junit4] 2> "eventTime":28830011194553214, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[28830011194553214], [junit4] 2> "preferredOperation":"movereplica", [junit4] 2> "_enqueue_time_":28830012848303864, [junit4] 2> "nodeNames":["127.0.0.1:10030_solr"]}} [junit4] 2> 170981 DEBUG (AutoscalingActionExecutor-151-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event { [junit4] 2> "id":"666cbe101f337eTbluweyejjslpxfyk4vqegzwde", [junit4] 2> "source":"node_lost_restore_trigger", [junit4] 2> "eventTime":28830011194553214, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[28830011194553214], [junit4] 2> "preferredOperation":"movereplica", [junit4] 2> "_enqueue_time_":28830012848303864, [junit4] 2> "nodeNames":["127.0.0.1:10030_solr"]}} [junit4] 2> 170981 DEBUG (AutoscalingActionExecutor-151-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_restore_trigger after 100ms [junit4] 2> 170981 DEBUG (AutoscalingActionExecutor-151-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms [junit4] 2> 170981 DEBUG (AutoscalingActionExecutor-151-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 31 ms for event id=666cbe101f337eTbluweyejjslpxfyk4vqegzwde [junit4] 2> 170981 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 170982 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now [junit4] 2> 170982 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now [junit4] 2> 170982 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor [junit4] 2> 170982 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor [junit4] 2> 170982 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely [junit4] 2> 170982 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 170983 INFO (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[C5143895DF8F38D5]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeLostTriggerRestoreState [junit4] OK 0.13s J2 | TestSimTriggerIntegration.testNodeLostTriggerRestoreState [junit4] 2> 170986 INFO (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[C5143895DF8F38D5]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEventFromRestoredState [junit4] 2> 170990 DEBUG (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10031_solr [junit4] 2> 170990 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers [junit4] 2> 170990 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1 [junit4] 2> 170991 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0 [junit4] 2> 170991 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1 [junit4] 2> 170991 DEBUG (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=0 [junit4] 2> 170991 DEBUG (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 0 [junit4] 2> 170991 INFO (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[C5143895DF8F38D5]) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory. [junit4] 2> 170992 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10031_solr, 127.0.0.1:10032_solr] [junit4] 2> 170993 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- cleaning old nodeLost / nodeAdded markers [junit4] 2> 170993 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1 [junit4] 2> 170993 DEBUG (ScheduledTrigger-156-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2 [junit4] 2> 170994 DEBUG (simCloudManagerPool-155-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 170994 DEBUG (simCloudManagerPool-155-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2 [junit4] 2> 170995 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2 [junit4] 2> 171006 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- cleaning old nodeLost / nodeAdded markers [junit4] 2> 171006 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2 [junit4] 2> 171008 DEBUG (simCloudManagerPool-155-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 171008 DEBUG (simCloudManagerPool-155-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3 [junit4] 2> 171009 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3 [junit4] 2> 171009 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestSimTriggerIntegration TestTriggerAction init [junit4] 2> 171009 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - Initial livenodes: [127.0.0.1:10031_solr, 127.0.0.1:10032_solr] [junit4] 2> 171009 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=10, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestSimTriggerIntegration$TestTriggerAction}], enabled=true} [junit4] 2> 171009 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- cleaning old nodeLost / nodeAdded markers [junit4] 2> 171009 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3 [junit4] 2> 171010 DEBUG (ScheduledTrigger-156-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 171010 DEBUG (ScheduledTrigger-156-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 171014 DEBUG (ScheduledTrigger-156-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2 [junit4] 2> 171014 DEBUG (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[C5143895DF8F38D5]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- creating marker: /autoscaling/nodeAdded/127.0.0.1:10033_solr [junit4] 2> 171030 DEBUG (ScheduledTrigger-156-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 171030 DEBUG (ScheduledTrigger-156-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 171030 DEBUG (ScheduledTrigger-156-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10033_solr at time 28830015376338364 [junit4] 2> 171034 DEBUG (ScheduledTrigger-156-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 2 [junit4] 2> 171051 DEBUG (ScheduledTrigger-156-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 171051 DEBUG (ScheduledTrigger-156-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 171055 DEBUG (ScheduledTrigger-156-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3 [junit4] 2> 171071 DEBUG (ScheduledTrigger-156-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 171071 DEBUG (ScheduledTrigger-156-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 171075 DEBUG (ScheduledTrigger-156-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3 [junit4] 2> 171091 DEBUG (ScheduledTrigger-156-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 171091 DEBUG (ScheduledTrigger-156-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 171095 DEBUG (ScheduledTrigger-156-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3 [junit4] 2> 171111 DEBUG (ScheduledTrigger-156-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 171111 DEBUG (ScheduledTrigger-156-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 171115 DEBUG (ScheduledTrigger-156-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3 [junit4] 2> 171132 DEBUG (ScheduledTrigger-156-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 171132 DEBUG (ScheduledTrigger-156-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 171136 DEBUG (ScheduledTrigger-156-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3 [junit4] 2> 171152 DEBUG (ScheduledTrigger-156-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 171152 DEBUG (ScheduledTrigger-156-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 171156 DEBUG (ScheduledTrigger-156-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3 [junit4] 2> 171172 DEBUG (ScheduledTrigger-156-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 171172 DEBUG (ScheduledTrigger-156-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 171176 DEBUG (ScheduledTrigger-156-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3 [junit4] 2> 171193 DEBUG (ScheduledTrigger-156-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 171193 DEBUG (ScheduledTrigger-156-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 171196 DEBUG (ScheduledTrigger-156-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3 [junit4] 2> 171213 DEBUG (ScheduledTrigger-156-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 171213 DEBUG (ScheduledTrigger-156-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 171217 DEBUG (ScheduledTrigger-156-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3 [junit4] 2> 171233 DEBUG (ScheduledTrigger-156-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 171233 DEBUG (ScheduledTrigger-156-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 171233 DEBUG (ScheduledTrigger-156-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10033_solr] added at times [28830015376338364], now=28830025527299614 [junit4] 2> 171234 DEBUG (ScheduledTrigger-156-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"666cbf09602dbcTbluweyejjslpxfyk4vqegzwdg", [junit4] 2> "source":"node_added_trigger", [junit4] 2> "eventTime":28830015376338364, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[28830015376338364], [junit4] 2> "preferredOperation":"movereplica", [junit4] 2> "nodeNames":["127.0.0.1:10033_solr"]}} [junit4] 2> 171234 DEBUG (ScheduledTrigger-156-thread-2) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger] [junit4] 2> 171234 DEBUG (ScheduledTrigger-156-thread-2) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event { [junit4] 2> "id":"666cbf09602dbcTbluweyejjslpxfyk4vqegzwdg", [junit4] 2> "source":"node_added_trigger", [junit4] 2> "eventTime":28830015376338364, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[28830015376338364], [junit4] 2> "preferredOperation":"movereplica", [junit4] 2> "_enqueue_time_":28830025556536464, [...truncated too long message...] ispatcher: [junit4] 2> [junit4] 2> Finalizer: [junit4] 2> java.lang.Object.wait(Native Method) [junit4] 2> java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144) [junit4] 2> java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165) [junit4] 2> java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216) [junit4] 2> [junit4] 2> Reference Handler: [junit4] 2> java.lang.Object.wait(Native Method) [junit4] 2> java.lang.Object.wait(Object.java:502) [junit4] 2> java.lang.ref.Reference.tryHandlePending(Reference.java:191) [junit4] 2> java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153) [junit4] 2> [junit4] 2> SUITE-BasicAuthIntegrationTest-seed#[837E4CFD909FEB20]-worker: [junit4] 2> java.lang.Thread.dumpThreads(Native Method) [junit4] 2> java.lang.Thread.getAllStackTraces(Thread.java:1610) [junit4] 2> org.apache.solr.SolrTestCaseJ4.clearObjectTrackerAndCheckEmpty(SolrTestCaseJ4.java:391) [junit4] 2> org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:318) [junit4] 2> [...sun.*, java.lang.reflect.*, com.carrotsearch.randomizedtesting.*] [junit4] 2> org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) [junit4] 2> org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) [junit4] 2> org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) [junit4] 2> org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> java.lang.Thread.run(Thread.java:748) [junit4] 2> [junit4] 2> main: [junit4] 2> java.lang.Object.wait(Native Method) [junit4] 2> java.lang.Thread.join(Thread.java:1252) [junit4] 2> java.lang.Thread.join(Thread.java:1326) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMain.execute(SlaveMain.java:269) [junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMain.main(SlaveMain.java:394) [junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe.main(SlaveMainSafe.java:13) [junit4] 2> [junit4] 2> JUnit4-serializer-daemon: [junit4] 2> java.lang.Thread.sleep(Native Method) [junit4] 2> com.carrotsearch.ant.tasks.junit4.events.Serializer$1.run(Serializer.java:50) [junit4] 2> [junit4] 2> Connection evictor: [junit4] 2> java.lang.Thread.sleep(Native Method) [junit4] 2> org.apache.http.impl.client.IdleConnectionEvictor$1.run(IdleConnectionEvictor.java:66) [junit4] 2> java.lang.Thread.run(Thread.java:748) [junit4] 2> [junit4] 2> SUITE-BasicAuthIntegrationTest-seed#[837E4CFD909FEB20]: [junit4] 2> java.lang.Thread.sleep(Native Method) [junit4] 2> [...com.carrotsearch.randomizedtesting.*] [junit4] 2> [junit4] 2> 216723 INFO (SUITE-BasicAuthIntegrationTest-seed#[837E4CFD909FEB20]-worker) [ ] o.a.s.SolrTestCaseJ4 ------------------------------------------------------- Done waiting for tracked resources to be released [junit4] 2> NOTE: test params are: codec=FastCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST, chunkSize=32354, maxDocsPerChunk=561, blockSize=352), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST, chunkSize=32354, blockSize=352)), sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@1392b6f5), locale=ca-ES, timezone=Etc/GMT+10 [junit4] 2> NOTE: Linux 4.4.0-112-generic amd64/Oracle Corporation 1.8.0_191 (64-bit)/cpus=4,threads=2,free=169121856,total=283115520 [junit4] 2> NOTE: All tests run in this JVM: [BasicAuthIntegrationTest, BasicAuthIntegrationTest] [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicAuthIntegrationTest -Dtests.seed=837E4CFD909FEB20 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=ca-ES -Dtests.timezone=Etc/GMT+10 -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [junit4] ERROR 0.00s J1 | BasicAuthIntegrationTest (suite) <<< [junit4] > Throwable #1: java.lang.AssertionError: ObjectTracker found 1 object(s) that were not released!!! [InternalHttpClient] [junit4] > org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.http.impl.client.InternalHttpClient [junit4] > at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) [junit4] > at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:321) [junit4] > at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:330) [junit4] > at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:268) [junit4] > at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:255) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.<init>(HttpSolrClient.java:201) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient$Builder.build(HttpSolrClient.java:964) [junit4] > at org.apache.solr.client.solrj.embedded.JettySolrRunner.newClient(JettySolrRunner.java:751) [junit4] > at org.apache.solr.security.BasicAuthIntegrationTest.testBasicAuth(BasicAuthIntegrationTest.java:247) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > expected null, but was:<ObjectTracker found 1 object(s) that were not released!!! [InternalHttpClient] [junit4] > org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.http.impl.client.InternalHttpClient [junit4] > at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) [junit4] > at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:321) [junit4] > at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:330) [junit4] > at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:268) [junit4] > at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:255) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.<init>(HttpSolrClient.java:201) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient$Builder.build(HttpSolrClient.java:964) [junit4] > at org.apache.solr.client.solrj.embedded.JettySolrRunner.newClient(JettySolrRunner.java:751) [junit4] > at org.apache.solr.security.BasicAuthIntegrationTest.testBasicAuth(BasicAuthIntegrationTest.java:247) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > > [junit4] > at __randomizedtesting.SeedInfo.seed([837E4CFD909FEB20]:0) [junit4] > at org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:319) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] Completed [5/5 (5!)] on J1 in 86.06s, 1 test, 1 failure <<< FAILURES! [junit4] [junit4] [junit4] Tests with failures [seed: 837E4CFD909FEB20]: [junit4] - org.apache.solr.security.BasicAuthIntegrationTest (suite) [junit4] - org.apache.solr.security.BasicAuthIntegrationTest (suite) [junit4] - org.apache.solr.security.BasicAuthIntegrationTest (suite) [junit4] - org.apache.solr.security.BasicAuthIntegrationTest.testBasicAuth [junit4] - org.apache.solr.security.BasicAuthIntegrationTest (suite) [junit4] [junit4] [junit4] JVM J0: 0.81 .. 156.19 = 155.37s [junit4] JVM J1: 0.78 .. 217.96 = 217.18s [junit4] JVM J2: 0.86 .. 131.56 = 130.69s [junit4] Execution time total: 3 minutes 37 seconds [junit4] Tests summary: 5 suites, 5 tests, 4 suite-level errors, 1 failure BUILD FAILED /home/jenkins/jenkins-slave/workspace/Lucene-Solr-repro/lucene/common-build.xml:1572: The following error occurred while executing this line: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-repro/lucene/common-build.xml:1099: There were test failures: 5 suites, 5 tests, 4 suite-level errors, 1 failure [seed: 837E4CFD909FEB20] Total time: 3 minutes 39 seconds [repro] Setting last failure code to 256 [repro] Failures at the tip of master without a seed: [repro] 5/5 failed: org.apache.solr.security.BasicAuthIntegrationTest [repro] git checkout e5fda5d6f1cc6010e6b3565aa4bd70be31621692 Note: checking out 'e5fda5d6f1cc6010e6b3565aa4bd70be31621692'. You are in 'detached HEAD' state. You can look around, make experimental changes and commit them, and you can discard any commits you make in this state without impacting any branches by performing another checkout. If you want to create a new branch to retain commits you create, you may do so (now or later) by using -b with the checkout command again. Example: git checkout -b <new-branch-name> HEAD is now at e5fda5d... SOLR-13050: Fix the test so that .system events are collected again. [repro] Exiting with code 256 Archiving artifacts [Fast Archiver] No artifacts from Lucene-Solr-repro Repro-Lucene-Solr-SmokeRelease-master#1224 to compare, so performing full copy of artifacts Recording test results Build step 'Publish JUnit test result report' changed build result to UNSTABLE Email was triggered for: Unstable (Test Failures) Sending email for trigger: Unstable (Test Failures)
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org
