Return-Path: X-Original-To: archive-asf-public-internal@cust-asf2.ponee.io Delivered-To: archive-asf-public-internal@cust-asf2.ponee.io Received: from cust-asf.ponee.io (cust-asf.ponee.io [163.172.22.183]) by cust-asf2.ponee.io (Postfix) with ESMTP id 438FB200D5F for ; Mon, 18 Dec 2017 19:01:22 +0100 (CET) Received: by cust-asf.ponee.io (Postfix) id 41CDD160C05; Mon, 18 Dec 2017 18:01:22 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id 94BD0160BFB for ; Mon, 18 Dec 2017 19:01:19 +0100 (CET) Received: (qmail 84322 invoked by uid 500); 18 Dec 2017 18:01:18 -0000 Mailing-List: contact dev-help@lucene.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@lucene.apache.org Delivered-To: mailing list dev@lucene.apache.org Received: (qmail 84312 invoked by uid 99); 18 Dec 2017 18:01:18 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd2-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 18 Dec 2017 18:01:18 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd2-us-west.apache.org (ASF Mail Server at spamd2-us-west.apache.org) with ESMTP id 6DCBD1A0933 for ; Mon, 18 Dec 2017 18:01:17 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd2-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: -0.3 X-Spam-Level: X-Spam-Status: No, score=-0.3 tagged_above=-999 required=6.31 tests=[KAM_BADIPHTTP=2, RCVD_IN_DNSWL_MED=-2.3, SPF_PASS=-0.001, WEIRD_PORT=0.001] autolearn=disabled Received: from mx1-lw-eu.apache.org ([10.40.0.8]) by localhost (spamd2-us-west.apache.org [10.40.0.9]) (amavisd-new, port 10024) with ESMTP id jOBx3uBaHeIV for ; Mon, 18 Dec 2017 18:01:02 +0000 (UTC) Received: from serv1.sd-datasolutions.de (serv1.sd-datasolutions.de [88.99.242.108]) by mx1-lw-eu.apache.org (ASF Mail Server at mx1-lw-eu.apache.org) with ESMTP id 63B895F51F for ; Mon, 18 Dec 2017 18:01:01 +0000 (UTC) Received: from serv1 (ip6-localhost [IPv6:::1]) by serv1.sd-datasolutions.de (Postfix) with ESMTP id 853F1108051D for ; Mon, 18 Dec 2017 18:01:00 +0000 (UTC) Date: Mon, 18 Dec 2017 17:59:43 +0000 (UTC) From: Policeman Jenkins Server To: dev@lucene.apache.org Message-ID: <2051750952.189.1513620060546.JavaMail.jenkins@serv1.sd-datasolutions.de> In-Reply-To: <1235666782.183.1513603951089.JavaMail.jenkins@serv1.sd-datasolutions.de> References: <1235666782.183.1513603951089.JavaMail.jenkins@serv1.sd-datasolutions.de> Subject: [JENKINS] Lucene-Solr-7.x-Linux (32bit/jdk1.8.0_144) - Build # 1011 - Still Unstable! MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_188_651998426.1513620060501" X-Jenkins-Job: Lucene-Solr-7.x-Linux X-Jenkins-Result: UNSTABLE archived-at: Mon, 18 Dec 2017 18:01:22 -0000 ------=_Part_188_651998426.1513620060501 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/1011/ Java: 32bit/jdk1.8.0_144 -server -XX:+UseParallelGC 3 tests failed. FAILED: junit.framework.TestSuite.org.apache.solr.cloud.TestSolrCloudWithS= ecureImpersonation Error Message: 2 threads leaked from SUITE scope at org.apache.solr.cloud.TestSolrCloudWit= hSecureImpersonation: 1) Thread[id=3D3777, name=3Djetty-launcher-872-th= read-1-EventThread, state=3DTIMED_WAITING, group=3DTGRP-TestSolrCloudWithSe= cureImpersonation] at sun.misc.Unsafe.park(Native Method) a= t java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) = at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSha= redNanos(AbstractQueuedSynchronizer.java:1037) at java.util.concurr= ent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSy= nchronizer.java:1328) at java.util.concurrent.CountDownLatch.await(= CountDownLatch.java:277) at org.apache.curator.CuratorZookeeperClie= nt.internalBlockUntilConnectedOrTimedOut(CuratorZookeeperClient.java:323) = at org.apache.curator.RetryLoop.callWithRetry(RetryLoop.java:105) = at org.apache.curator.framework.imps.GetDataBuilderImpl.pathInForegro= und(GetDataBuilderImpl.java:288) at org.apache.curator.framework.im= ps.GetDataBuilderImpl.forPath(GetDataBuilderImpl.java:279) at org.a= pache.curator.framework.imps.GetDataBuilderImpl.forPath(GetDataBuilderImpl.= java:41) at org.apache.curator.framework.recipes.shared.SharedValue= .readValue(SharedValue.java:244) at org.apache.curator.framework.re= cipes.shared.SharedValue.access$100(SharedValue.java:44) at org.apa= che.curator.framework.recipes.shared.SharedValue$1.process(SharedValue.java= :61) at org.apache.curator.framework.imps.NamespaceWatcher.process(= NamespaceWatcher.java:67) at org.apache.zookeeper.ClientCnxn$EventT= hread.processEvent(ClientCnxn.java:530) at org.apache.zookeeper.Cli= entCnxn$EventThread.run(ClientCnxn.java:505) 2) Thread[id=3D3776, name= =3Djetty-launcher-872-thread-2-EventThread, state=3DTIMED_WAITING, group=3D= TGRP-TestSolrCloudWithSecureImpersonation] at sun.misc.Unsafe.park(= Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(= LockSupport.java:215) at java.util.concurrent.locks.AbstractQueuedS= ynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1037) = at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireShar= edNanos(AbstractQueuedSynchronizer.java:1328) at java.util.concurre= nt.CountDownLatch.await(CountDownLatch.java:277) at org.apache.cura= tor.CuratorZookeeperClient.internalBlockUntilConnectedOrTimedOut(CuratorZoo= keeperClient.java:323) at org.apache.curator.RetryLoop.callWithRetr= y(RetryLoop.java:105) at org.apache.curator.framework.imps.GetDataB= uilderImpl.pathInForeground(GetDataBuilderImpl.java:288) at org.apa= che.curator.framework.imps.GetDataBuilderImpl.forPath(GetDataBuilderImpl.ja= va:279) at org.apache.curator.framework.imps.GetDataBuilderImpl.for= Path(GetDataBuilderImpl.java:41) at org.apache.curator.framework.re= cipes.shared.SharedValue.readValue(SharedValue.java:244) at org.apa= che.curator.framework.recipes.shared.SharedValue.access$100(SharedValue.jav= a:44) at org.apache.curator.framework.recipes.shared.SharedValue$1.= process(SharedValue.java:61) at org.apache.curator.framework.imps.N= amespaceWatcher.process(NamespaceWatcher.java:67) at org.apache.zoo= keeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:530) at = org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:505) Stack Trace: com.carrotsearch.randomizedtesting.ThreadLeakError: 2 threads leaked from S= UITE scope at org.apache.solr.cloud.TestSolrCloudWithSecureImpersonation:= =20 1) Thread[id=3D3777, name=3Djetty-launcher-872-thread-1-EventThread, sta= te=3DTIMED_WAITING, group=3DTGRP-TestSolrCloudWithSecureImpersonation] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.jav= a:215) at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireS= haredNanos(AbstractQueuedSynchronizer.java:1037) at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquire= SharedNanos(AbstractQueuedSynchronizer.java:1328) at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:27= 7) at org.apache.curator.CuratorZookeeperClient.internalBlockUntilConn= ectedOrTimedOut(CuratorZookeeperClient.java:323) at org.apache.curator.RetryLoop.callWithRetry(RetryLoop.java:105) at org.apache.curator.framework.imps.GetDataBuilderImpl.pathInForeg= round(GetDataBuilderImpl.java:288) at org.apache.curator.framework.imps.GetDataBuilderImpl.forPath(Get= DataBuilderImpl.java:279) at org.apache.curator.framework.imps.GetDataBuilderImpl.forPath(Get= DataBuilderImpl.java:41) at org.apache.curator.framework.recipes.shared.SharedValue.readValu= e(SharedValue.java:244) at org.apache.curator.framework.recipes.shared.SharedValue.access$1= 00(SharedValue.java:44) at org.apache.curator.framework.recipes.shared.SharedValue$1.proces= s(SharedValue.java:61) at org.apache.curator.framework.imps.NamespaceWatcher.process(Names= paceWatcher.java:67) at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientC= nxn.java:530) at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:= 505) 2) Thread[id=3D3776, name=3Djetty-launcher-872-thread-2-EventThread, sta= te=3DTIMED_WAITING, group=3DTGRP-TestSolrCloudWithSecureImpersonation] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.jav= a:215) at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireS= haredNanos(AbstractQueuedSynchronizer.java:1037) at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquire= SharedNanos(AbstractQueuedSynchronizer.java:1328) at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:27= 7) at org.apache.curator.CuratorZookeeperClient.internalBlockUntilConn= ectedOrTimedOut(CuratorZookeeperClient.java:323) at org.apache.curator.RetryLoop.callWithRetry(RetryLoop.java:105) at org.apache.curator.framework.imps.GetDataBuilderImpl.pathInForeg= round(GetDataBuilderImpl.java:288) at org.apache.curator.framework.imps.GetDataBuilderImpl.forPath(Get= DataBuilderImpl.java:279) at org.apache.curator.framework.imps.GetDataBuilderImpl.forPath(Get= DataBuilderImpl.java:41) at org.apache.curator.framework.recipes.shared.SharedValue.readValu= e(SharedValue.java:244) at org.apache.curator.framework.recipes.shared.SharedValue.access$1= 00(SharedValue.java:44) at org.apache.curator.framework.recipes.shared.SharedValue$1.proces= s(SharedValue.java:61) at org.apache.curator.framework.imps.NamespaceWatcher.process(Names= paceWatcher.java:67) at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientC= nxn.java:530) at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:= 505) =09at __randomizedtesting.SeedInfo.seed([70A943F10BDA666F]:0) FAILED: junit.framework.TestSuite.org.apache.solr.uninverting.TestFieldCac= heVsDocValues Error Message: The test or suite printed 13392 bytes to stdout and stderr, even though the= limit was set to 8192 bytes. Increase the limit with @Limit, ignore it com= pletely with @SuppressSysoutChecks or run with -Dtests.verbose=3Dtrue Stack Trace: java.lang.AssertionError: The test or suite printed 13392 bytes to stdout a= nd stderr, even though the limit was set to 8192 bytes. Increase the limit = with @Limit, ignore it completely with @SuppressSysoutChecks or run with -D= tests.verbose=3Dtrue =09at __randomizedtesting.SeedInfo.seed([70A943F10BDA666F]:0) =09at org.apache.lucene.util.TestRuleLimitSysouts.afterIfSuccessful(TestRul= eLimitSysouts.java:211) =09at com.carrotsearch.randomizedtesting.rules.TestRuleAdapter$1.afterIfSuc= cessful(TestRuleAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:37) =09at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:53) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:47) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:64) =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIg= noreTestSuites.java:54) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:368) =09at java.lang.Thread.run(Thread.java:748) FAILED: junit.framework.TestSuite.org.apache.solr.uninverting.TestNumericT= erms32 Error Message: The test or suite printed 8912 bytes to stdout and stderr, even though the = limit was set to 8192 bytes. Increase the limit with @Limit, ignore it comp= letely with @SuppressSysoutChecks or run with -Dtests.verbose=3Dtrue Stack Trace: java.lang.AssertionError: The test or suite printed 8912 bytes to stdout an= d stderr, even though the limit was set to 8192 bytes. Increase the limit w= ith @Limit, ignore it completely with @SuppressSysoutChecks or run with -Dt= ests.verbose=3Dtrue =09at __randomizedtesting.SeedInfo.seed([70A943F10BDA666F]:0) =09at org.apache.lucene.util.TestRuleLimitSysouts.afterIfSuccessful(TestRul= eLimitSysouts.java:211) =09at com.carrotsearch.randomizedtesting.rules.TestRuleAdapter$1.afterIfSuc= cessful(TestRuleAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:37) =09at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:53) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:47) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:64) =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIg= noreTestSuites.java:54) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:368) =09at java.lang.Thread.run(Thread.java:748) Build Log: [...truncated 11966 lines...] [junit4] Suite: org.apache.solr.cloud.TestSolrCloudWithSecureImpersonati= on [junit4] 2> 286386 INFO (SUITE-TestSolrCloudWithSecureImpersonation-s= eed#[70A943F10BDA666F]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom san= ity checks: test.solr.allowed.securerandom=3Dnull & java.security.egd=3Dfil= e:/dev/./urandom [junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.x-= Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestSolrCloudWithSecureI= mpersonation_70A943F10BDA666F-001/init-core-data-001 [junit4] 2> 286386 WARN (SUITE-TestSolrCloudWithSecureImpersonation-s= eed#[70A943F10BDA666F]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSea= rchers: numOpens=3D71 numCloses=3D71 [junit4] 2> 286386 INFO (SUITE-TestSolrCloudWithSecureImpersonation-s= eed#[70A943F10BDA666F]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointField= s (NUMERIC_POINTS_SYSPROP=3Dtrue) w/NUMERIC_DOCVALUES_SYSPROP=3Dfalse [junit4] 2> 286388 INFO (SUITE-TestSolrCloudWithSecureImpersonation-s= eed#[70A943F10BDA666F]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (= false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason= =3D, ssl=3DNaN, value=3DNaN, clientAuth=3DNaN) [junit4] 2> 286407 INFO (SUITE-TestSolrCloudWithSecureImpersonation-s= eed#[70A943F10BDA666F]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting= cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr= /build/solr-core/test/J2/temp/solr.cloud.TestSolrCloudWithSecureImpersonati= on_70A943F10BDA666F-001/tempDir-001 [junit4] 2> 286407 INFO (SUITE-TestSolrCloudWithSecureImpersonation-s= eed#[70A943F10BDA666F]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST= SERVER [junit4] 2> 286407 INFO (Thread-856) [ ] o.a.s.c.ZkTestServer clie= nt port:0.0.0.0/0.0.0.0:0 [junit4] 2> 286407 INFO (Thread-856) [ ] o.a.s.c.ZkTestServer Star= ting server [junit4] 2> 286411 ERROR (Thread-856) [ ] o.a.z.s.ZooKeeperServer Z= KShutdownHandler is not registered, so ZooKeeper server won't take any acti= on on ERROR or SHUTDOWN server state changes [junit4] 2> 286507 INFO (SUITE-TestSolrCloudWithSecureImpersonation-s= eed#[70A943F10BDA666F]-worker) [ ] o.a.s.c.ZkTestServer start zk server = on port:33473 [junit4] 2> 286509 INFO (zkConnectionManagerCallback-875-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 286516 INFO (jetty-launcher-872-thread-1) [ ] o.e.j.s.= Server jetty-9.3.20.v20170531 [junit4] 2> 286516 INFO (jetty-launcher-872-thread-2) [ ] o.e.j.s.= Server jetty-9.3.20.v20170531 [junit4] 2> 286519 INFO (jetty-launcher-872-thread-2) [ ] o.e.j.s.= h.ContextHandler Started o.e.j.s.ServletContextHandler@5bc2c{/solr,null,AVA= ILABLE} [junit4] 2> 286520 INFO (jetty-launcher-872-thread-1) [ ] o.e.j.s.= h.ContextHandler Started o.e.j.s.ServletContextHandler@1875445{/solr,null,A= VAILABLE} [junit4] 2> 286522 INFO (jetty-launcher-872-thread-2) [ ] o.e.j.s.= AbstractConnector Started ServerConnector@11f1670{HTTP/1.1,[http/1.1]}{127.= 0.0.1:38887} [junit4] 2> 286522 INFO (jetty-launcher-872-thread-1) [ ] o.e.j.s.= AbstractConnector Started ServerConnector@17b8a4c{HTTP/1.1,[http/1.1]}{127.= 0.0.1:39099} [junit4] 2> 286522 INFO (jetty-launcher-872-thread-2) [ ] o.e.j.s.= Server Started @288859ms [junit4] 2> 286522 INFO (jetty-launcher-872-thread-1) [ ] o.e.j.s.= Server Started @288859ms [junit4] 2> 286522 INFO (jetty-launcher-872-thread-2) [ ] o.a.s.c.= s.e.JettySolrRunner Jetty properties: {hostContext=3D/solr, hostPort=3D3888= 7} [junit4] 2> 286522 INFO (jetty-launcher-872-thread-1) [ ] o.a.s.c.= s.e.JettySolrRunner Jetty properties: {hostContext=3D/solr, hostPort=3D3909= 9} [junit4] 2> 286522 ERROR (jetty-launcher-872-thread-2) [ ] o.a.s.u.= StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missin= g or incomplete. [junit4] 2> 286522 ERROR (jetty-launcher-872-thread-1) [ ] o.a.s.u.= StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missin= g or incomplete. [junit4] 2> 286522 INFO (jetty-launcher-872-thread-2) [ ] o.a.s.s.= SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.3.0 [junit4] 2> 286522 INFO (jetty-launcher-872-thread-1) [ ] o.a.s.s.= SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.3.0 [junit4] 2> 286522 INFO (jetty-launcher-872-thread-2) [ ] o.a.s.s.= SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 286522 INFO (jetty-launcher-872-thread-1) [ ] o.a.s.s.= SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 286522 INFO (jetty-launcher-872-thread-2) [ ] o.a.s.s.= SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 286522 INFO (jetty-launcher-872-thread-1) [ ] o.a.s.s.= SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 286522 INFO (jetty-launcher-872-thread-2) [ ] o.a.s.s.= SolrDispatchFilter |___/\___/_|_| Start time: 2017-12-18T17:11:27.523Z [junit4] 2> 286522 INFO (jetty-launcher-872-thread-1) [ ] o.a.s.s.= SolrDispatchFilter |___/\___/_|_| Start time: 2017-12-18T17:11:27.523Z [junit4] 2> 286527 INFO (zkConnectionManagerCallback-879-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 286527 INFO (zkConnectionManagerCallback-877-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 286528 INFO (jetty-launcher-872-thread-1) [ ] o.a.s.s.= SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 286528 INFO (jetty-launcher-872-thread-2) [ ] o.a.s.s.= SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 286532 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ = ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from = client sessionid 0x1606a9bdbb10001, likely client has closed socket [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOSe= rverCnxn.java:239) [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxnFactory.run= (NIOServerCnxnFactory.java:203) [junit4] 2> =09at java.lang.Thread.run(Thread.java:748) [junit4] 2> 286540 INFO (jetty-launcher-872-thread-1) [ ] o.a.s.c.= ZkContainer Zookeeper client=3D127.0.0.1:33473/solr [junit4] 2> 286543 INFO (jetty-launcher-872-thread-2) [ ] o.a.s.c.= ZkContainer Zookeeper client=3D127.0.0.1:33473/solr [junit4] 2> 286565 INFO (zkConnectionManagerCallback-884-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 286565 INFO (zkConnectionManagerCallback-887-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 286575 INFO (zkConnectionManagerCallback-889-thread-1-pro= cessing-n:127.0.0.1:38887_solr) [n:127.0.0.1:38887_solr ] o.a.s.c.c.Conn= ectionManager zkClient has connected [junit4] 2> 286575 INFO (zkConnectionManagerCallback-891-thread-1-pro= cessing-n:127.0.0.1:39099_solr) [n:127.0.0.1:39099_solr ] o.a.s.c.c.Conn= ectionManager zkClient has connected [junit4] 2> 286625 INFO (jetty-launcher-872-thread-1) [n:127.0.0.1:39= 099_solr ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 286625 INFO (jetty-launcher-872-thread-2) [n:127.0.0.1:38= 887_solr ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 286626 INFO (jetty-launcher-872-thread-1) [n:127.0.0.1:39= 099_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 1= 27.0.0.1:39099_solr [junit4] 2> 286626 INFO (jetty-launcher-872-thread-2) [n:127.0.0.1:38= 887_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live= _nodes/127.0.0.1:38887_solr [junit4] 2> 286626 INFO (jetty-launcher-872-thread-1) [n:127.0.0.1:39= 099_solr ] o.a.s.c.Overseer Overseer (id=3D99196409440436230-127.0.0.1:3= 9099_solr-n_0000000000) starting [junit4] 2> 286645 INFO (zkCallback-888-thread-1-processing-n:127.0.0= .1:38887_solr) [n:127.0.0.1:38887_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 286663 INFO (zkCallback-890-thread-1-processing-n:127.0.0= .1:39099_solr) [n:127.0.0.1:39099_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 286680 INFO (jetty-launcher-872-thread-1) [n:127.0.0.1:39= 099_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live= _nodes/127.0.0.1:39099_solr [junit4] 2> 286683 INFO (zkCallback-890-thread-1-processing-n:127.0.0= .1:39099_solr) [n:127.0.0.1:39099_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 286685 INFO (zkCallback-888-thread-1-processing-n:127.0.0= .1:38887_solr) [n:127.0.0.1:38887_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 286754 INFO (jetty-launcher-872-thread-2) [n:127.0.0.1:38= 887_solr ] o.a.s.c.CoreContainer Initializing authentication plugin: org= .apache.solr.security.HttpParamDelegationTokenPlugin [junit4] 2> 286760 WARN (jetty-launcher-872-thread-2) [n:127.0.0.1:38= 887_solr ] o.a.s.c.s.i.Krb5HttpClientBuilder org.apache.solr.client.solr= j.impl.Krb5HttpClientBuilder is configured without specifying system proper= ty 'java.security.auth.login.config' [junit4] 2> 286765 INFO (jetty-launcher-872-thread-2) [n:127.0.0.1:38= 887_solr ] o.a.s.s.KerberosPlugin Params: {solr.kerberos.impersonator.us= er.noGroups.hosts=3D*, solr.kerberos.impersonator.user.bogusGroup.groups=3D= __some_bogus_group, token.valid=3D30, cookie.domain=3D127.0.0.1, solr.kerbe= ros.impersonator.user.anyHostAnyUser.groups=3D*, solr.kerberos.impersonator= .user.bogusGroup.hosts=3D*, solr.kerberos.impersonator.user.anyHostAnyUser.= hosts=3D*, token.validity=3D36000, solr.kerberos.impersonator.user.noHosts.= groups=3D*, type=3Dkerberos, solr.kerberos.impersonator.user.localHostAnyGr= oup.groups=3D*, delegation-token.token-kind=3Dsolr-dt, solr.kerberos.impers= onator.user.wrongHost.hosts=3D1.1.1.1.1.1, cookie.path=3D/, zk-dt-secret-ma= nager.znodeWorkingPath=3Dsolr/security/zkdtsm, solr.kerberos.impersonator.u= ser.localHostAnyGroup.hosts=3Dlocalhost.localdomain,localhost,127.0.0.1, si= gner.secret.provider.zookeeper.path=3D/token, solr.kerberos.impersonator.us= er.anyHostUsersGroup.groups=3Djenkins, zk-dt-secret-manager.enable=3Dtrue, = solr.kerberos.impersonator.user.wrongHost.groups=3D*, kerberos.name.rules= =3DDEFAULT, signer.secret.provider=3Dzookeeper, solr.kerberos.impersonator.= user.anyHostUsersGroup.hosts=3D*} [junit4] 2> 286799 INFO (jetty-launcher-872-thread-1) [n:127.0.0.1:39= 099_solr ] o.a.s.c.CoreContainer Initializing authentication plugin: org= .apache.solr.security.HttpParamDelegationTokenPlugin [junit4] 2> 286799 WARN (jetty-launcher-872-thread-1) [n:127.0.0.1:39= 099_solr ] o.a.s.c.s.i.Krb5HttpClientBuilder org.apache.solr.client.solr= j.impl.Krb5HttpClientBuilder is configured without specifying system proper= ty 'java.security.auth.login.config' [junit4] 2> 286800 INFO (jetty-launcher-872-thread-1) [n:127.0.0.1:39= 099_solr ] o.a.s.s.KerberosPlugin Params: {solr.kerberos.impersonator.us= er.noGroups.hosts=3D*, solr.kerberos.impersonator.user.bogusGroup.groups=3D= __some_bogus_group, token.valid=3D30, cookie.domain=3D127.0.0.1, solr.kerbe= ros.impersonator.user.anyHostAnyUser.groups=3D*, solr.kerberos.impersonator= .user.bogusGroup.hosts=3D*, solr.kerberos.impersonator.user.anyHostAnyUser.= hosts=3D*, token.validity=3D36000, solr.kerberos.impersonator.user.noHosts.= groups=3D*, type=3Dkerberos, solr.kerberos.impersonator.user.localHostAnyGr= oup.groups=3D*, delegation-token.token-kind=3Dsolr-dt, solr.kerberos.impers= onator.user.wrongHost.hosts=3D1.1.1.1.1.1, cookie.path=3D/, zk-dt-secret-ma= nager.znodeWorkingPath=3Dsolr/security/zkdtsm, solr.kerberos.impersonator.u= ser.localHostAnyGroup.hosts=3Dlocalhost.localdomain,localhost,127.0.0.1, si= gner.secret.provider.zookeeper.path=3D/token, solr.kerberos.impersonator.us= er.anyHostUsersGroup.groups=3Djenkins, zk-dt-secret-manager.enable=3Dtrue, = solr.kerberos.impersonator.user.wrongHost.groups=3D*, kerberos.name.rules= =3DDEFAULT, signer.secret.provider=3Dzookeeper, solr.kerberos.impersonator.= user.anyHostUsersGroup.hosts=3D*} [junit4] 2> 286830 INFO (jetty-launcher-872-thread-2) [n:127.0.0.1:38= 887_solr ] o.a.c.f.i.CuratorFrameworkImpl Starting [junit4] 2> 286830 INFO (jetty-launcher-872-thread-1) [n:127.0.0.1:39= 099_solr ] o.a.c.f.i.CuratorFrameworkImpl Starting [junit4] 2> 286859 INFO (jetty-launcher-872-thread-1-EventThread) [n:= 127.0.0.1:39099_solr ] o.a.c.f.s.ConnectionStateManager State change: CO= NNECTED [junit4] 2> 286860 INFO (jetty-launcher-872-thread-2-EventThread) [n:= 127.0.0.1:38887_solr ] o.a.c.f.s.ConnectionStateManager State change: CO= NNECTED [junit4] 2> 286950 WARN (jetty-launcher-872-thread-2) [n:127.0.0.1:38= 887_solr ] o.a.s.c.s.i.Krb5HttpClientBuilder org.apache.solr.client.solr= j.impl.Krb5HttpClientBuilder is configured without specifying system proper= ty 'java.security.auth.login.config' [junit4] 2> 286950 WARN (jetty-launcher-872-thread-1) [n:127.0.0.1:39= 099_solr ] o.a.s.c.s.i.Krb5HttpClientBuilder org.apache.solr.client.solr= j.impl.Krb5HttpClientBuilder is configured without specifying system proper= ty 'java.security.auth.login.config' [junit4] 2> 286995 INFO (jetty-launcher-872-thread-2) [n:127.0.0.1:38= 887_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38887.solr= .node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.Jm= xMBeanServer@13c7785 [junit4] 2> 286998 INFO (jetty-launcher-872-thread-1) [n:127.0.0.1:39= 099_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39099.solr= .node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.Jm= xMBeanServer@13c7785 [junit4] 2> 287009 INFO (jetty-launcher-872-thread-1) [n:127.0.0.1:39= 099_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39099.solr= .jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxM= BeanServer@13c7785 [junit4] 2> 287009 INFO (jetty-launcher-872-thread-1) [n:127.0.0.1:39= 099_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39099.solr= .jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.= JmxMBeanServer@13c7785 [junit4] 2> 287010 INFO (jetty-launcher-872-thread-2) [n:127.0.0.1:38= 887_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38887.solr= .jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxM= BeanServer@13c7785 [junit4] 2> 287010 INFO (jetty-launcher-872-thread-2) [n:127.0.0.1:38= 887_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38887.solr= .jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.= JmxMBeanServer@13c7785 [junit4] 2> 287011 INFO (jetty-launcher-872-thread-1) [n:127.0.0.1:39= 099_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions undern= eath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/tes= t/J2/temp/solr.cloud.TestSolrCloudWithSecureImpersonation_70A943F10BDA666F-= 001/tempDir-001/node1/. [junit4] 2> 287011 INFO (jetty-launcher-872-thread-2) [n:127.0.0.1:38= 887_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions undern= eath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/tes= t/J2/temp/solr.cloud.TestSolrCloudWithSecureImpersonation_70A943F10BDA666F-= 001/tempDir-001/node2/. [junit4] 2> 287045 INFO (zkConnectionManagerCallback-897-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 287072 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyValidateGroup-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 #= ##Starting testProxyValidateGroup [junit4] 2> 287097 INFO (qtp10807214-3734) [n:127.0.0.1:39099_solr = ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params= doAs=3Djenkins&action=3DLIST&wt=3Djavabin&version=3D2 and sendToOCPQueue= =3Dtrue [junit4] 2> 287098 INFO (qtp10807214-3734) [n:127.0.0.1:39099_solr = ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/collections par= ams=3D{doAs=3Djenkins&action=3DLIST&wt=3Djavabin&version=3D2} status=3D0 QT= ime=3D2 [junit4] 2> 287104 WARN (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyValidateGroup-seed#[70A943F10BDA666F]) [ ] o.a.h.c.p.ResponseProc= essCookies Invalid cookie header: "Set-Cookie: hadoop.auth=3D"u=3DanyHostUs= ersGroup&p=3DanyHostUsersGroup&t=3Dtest&e=3D1513653088084&s=3Do++LYo1z3vyTa= 9OAKvqw+QDCpgI=3D"; Path=3D/; Domain=3D127.0.0.1; Expires=3D=C3=BEri., 19-d= es.-2017 03:11:28 GMT; HttpOnly". Invalid 'expires' attribute: =C3=BEri., 1= 9-des.-2017 03:11:28 GMT [junit4] 2> 287105 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyValidateGroup-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 #= ##Ending testProxyValidateGroup [junit4] 2> 287133 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyInvalidRemote-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 #= ##Starting testProxyInvalidRemote [junit4] 2> 287153 WARN (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyInvalidRemote-seed#[70A943F10BDA666F]) [ ] o.a.h.c.p.ResponseProc= essCookies Invalid cookie header: "Set-Cookie: hadoop.auth=3D"u=3DlocalHost= AnyGroup&p=3DlocalHostAnyGroup&t=3Dtest&e=3D1513653088134&s=3DoZ8FP+k9VFd3O= p/uMxxtvLqQEGY=3D"; Path=3D/; Domain=3D127.0.0.1; Expires=3D=C3=BEri., 19-d= es.-2017 03:11:28 GMT; HttpOnly". Invalid 'expires' attribute: =C3=BEri., 1= 9-des.-2017 03:11:28 GMT [junit4] 2> 287153 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyInvalidRemote-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 #= ##Ending testProxyInvalidRemote [junit4] 2> 287173 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyWrongHost-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 ###St= arting testProxyWrongHost [junit4] 2> 287191 WARN (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyWrongHost-seed#[70A943F10BDA666F]) [ ] o.a.h.c.p.ResponseProcessC= ookies Invalid cookie header: "Set-Cookie: hadoop.auth=3D"u=3DwrongHost&p= =3DwrongHost&t=3Dtest&e=3D1513653088178&s=3D5hSl7vokLiBQ81gMwZ5XSBWgOTk=3D"= ; Path=3D/; Domain=3D127.0.0.1; Expires=3D=C3=BEri., 19-des.-2017 03:11:28 = GMT; HttpOnly". Invalid 'expires' attribute: =C3=BEri., 19-des.-2017 03:11:= 28 GMT [junit4] 2> 287192 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyWrongHost-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 ###En= ding testProxyWrongHost [junit4] 2> 287222 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyNullProxyUser-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 #= ##Starting testProxyNullProxyUser [junit4] 2> 287222 INFO (qtp10807214-3724) [ ] o.a.s.s.SolrDispatc= hFilter Error authenticating [junit4] 2> java.lang.IllegalArgumentException: userName is NULL, empt= y or contains a '&' [junit4] 2> =09at org.apache.hadoop.security.authentication.util.AuthT= oken.checkForIllegalArgument(AuthToken.java:87) [junit4] 2> =09at org.apache.hadoop.security.authentication.util.AuthT= oken.(AuthToken.java:70) [junit4] 2> =09at org.apache.hadoop.security.authentication.server.Aut= henticationToken.(AuthenticationToken.java:58) [junit4] 2> =09at org.apache.solr.security.HttpParamDelegationTokenPlu= gin$HttpParamDelegationTokenAuthenticationHandler$HttpParamAuthenticationHa= ndler.authenticate(HttpParamDelegationTokenPlugin.java:213) [junit4] 2> =09at org.apache.hadoop.security.token.delegation.web.Dele= gationTokenAuthenticationHandler.authenticate(DelegationTokenAuthentication= Handler.java:348) [junit4] 2> =09at org.apache.solr.security.RequestContinuesRecorderAut= henticationHandler.authenticate(RequestContinuesRecorderAuthenticationHandl= er.java:69) [junit4] 2> =09at org.apache.hadoop.security.authentication.server.Aut= henticationFilter.doFilter(AuthenticationFilter.java:518) [junit4] 2> =09at org.apache.solr.security.DelegationTokenKerberosFilt= er.doFilter(DelegationTokenKerberosFilter.java:134) [junit4] 2> =09at org.apache.solr.security.HttpParamDelegationTokenPlu= gin$HttpParamToRequestFilter.doFilter(HttpParamDelegationTokenPlugin.java:2= 45) [junit4] 2> =09at org.apache.solr.security.KerberosPlugin.doAuthentica= te(KerberosPlugin.java:243) [junit4] 2> =09at org.apache.solr.servlet.SolrDispatchFilter.authentic= ateRequest(SolrDispatchFilter.java:451) [junit4] 2> =09at org.apache.solr.servlet.SolrDispatchFilter.doFilter(= SolrDispatchFilter.java:347) [junit4] 2> =09at org.apache.solr.servlet.SolrDispatchFilter.doFilter(= SolrDispatchFilter.java:326) [junit4] 2> =09at org.eclipse.jetty.servlet.ServletHandler$CachedChain= .doFilter(ServletHandler.java:1759) [junit4] 2> =09at org.apache.solr.client.solrj.embedded.JettySolrRunne= r$DebugFilter.doFilter(JettySolrRunner.java:139) [junit4] 2> =09at org.eclipse.jetty.servlet.ServletHandler$CachedChain= .doFilter(ServletHandler.java:1759) [junit4] 2> =09at org.eclipse.jetty.servlet.ServletHandler.doHandle(Se= rvletHandler.java:582) [junit4] 2> =09at org.eclipse.jetty.server.session.SessionHandler.doHa= ndle(SessionHandler.java:224) [junit4] 2> =09at org.eclipse.jetty.server.handler.ContextHandler.doHa= ndle(ContextHandler.java:1180) [junit4] 2> =09at org.eclipse.jetty.servlet.ServletHandler.doScope(Ser= vletHandler.java:512) [junit4] 2> =09at org.eclipse.jetty.server.session.SessionHandler.doSc= ope(SessionHandler.java:185) [junit4] 2> =09at org.eclipse.jetty.server.handler.ContextHandler.doSc= ope(ContextHandler.java:1112) [junit4] 2> =09at org.eclipse.jetty.server.handler.ScopedHandler.handl= e(ScopedHandler.java:141) [junit4] 2> =09at org.eclipse.jetty.server.handler.gzip.GzipHandler.ha= ndle(GzipHandler.java:493) [junit4] 2> =09at org.eclipse.jetty.server.handler.HandlerWrapper.hand= le(HandlerWrapper.java:134) [junit4] 2> =09at org.eclipse.jetty.server.Server.handle(Server.java:5= 34) [junit4] 2> =09at org.eclipse.jetty.server.HttpChannel.handle(HttpChan= nel.java:320) [junit4] 2> =09at org.eclipse.jetty.server.HttpConnection.onFillable(H= ttpConnection.java:251) [junit4] 2> =09at org.eclipse.jetty.io.AbstractConnection$ReadCallback= .succeeded(AbstractConnection.java:283) [junit4] 2> =09at org.eclipse.jetty.io.FillInterest.fillable(FillInter= est.java:108) [junit4] 2> =09at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(Sel= ectChannelEndPoint.java:93) [junit4] 2> =09at org.eclipse.jetty.util.thread.strategy.ExecuteProduc= eConsume.executeProduceConsume(ExecuteProduceConsume.java:303) [junit4] 2> =09at org.eclipse.jetty.util.thread.strategy.ExecuteProduc= eConsume.produceConsume(ExecuteProduceConsume.java:148) [junit4] 2> =09at org.eclipse.jetty.util.thread.strategy.ExecuteProduc= eConsume.run(ExecuteProduceConsume.java:136) [junit4] 2> =09at org.eclipse.jetty.util.thread.QueuedThreadPool.runJo= b(QueuedThreadPool.java:671) [junit4] 2> =09at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run= (QueuedThreadPool.java:589) [junit4] 2> =09at java.lang.Thread.run(Thread.java:748) [junit4] 2> 287223 WARN (qtp10807214-3724) [ ] o.e.j.s.ServletHand= ler /solr/admin/collections [junit4] 2> org.apache.solr.common.SolrException: Error during request= authentication,=20 [junit4] 2> =09at org.apache.solr.servlet.SolrDispatchFilter.authentic= ateRequest(SolrDispatchFilter.java:457) [junit4] 2> =09at org.apache.solr.servlet.SolrDispatchFilter.doFilter(= SolrDispatchFilter.java:347) [junit4] 2> =09at org.apache.solr.servlet.SolrDispatchFilter.doFilter(= SolrDispatchFilter.java:326) [junit4] 2> =09at org.eclipse.jetty.servlet.ServletHandler$CachedChain= .doFilter(ServletHandler.java:1759) [junit4] 2> =09at org.apache.solr.client.solrj.embedded.JettySolrRunne= r$DebugFilter.doFilter(JettySolrRunner.java:139) [junit4] 2> =09at org.eclipse.jetty.servlet.ServletHandler$CachedChain= .doFilter(ServletHandler.java:1759) [junit4] 2> =09at org.eclipse.jetty.servlet.ServletHandler.doHandle(Se= rvletHandler.java:582) [junit4] 2> =09at org.eclipse.jetty.server.session.SessionHandler.doHa= ndle(SessionHandler.java:224) [junit4] 2> =09at org.eclipse.jetty.server.handler.ContextHandler.doHa= ndle(ContextHandler.java:1180) [junit4] 2> =09at org.eclipse.jetty.servlet.ServletHandler.doScope(Ser= vletHandler.java:512) [junit4] 2> =09at org.eclipse.jetty.server.session.SessionHandler.doSc= ope(SessionHandler.java:185) [junit4] 2> =09at org.eclipse.jetty.server.handler.ContextHandler.doSc= ope(ContextHandler.java:1112) [junit4] 2> =09at org.eclipse.jetty.server.handler.ScopedHandler.handl= e(ScopedHandler.java:141) [junit4] 2> =09at org.eclipse.jetty.server.handler.gzip.GzipHandler.ha= ndle(GzipHandler.java:493) [junit4] 2> =09at org.eclipse.jetty.server.handler.HandlerWrapper.hand= le(HandlerWrapper.java:134) [junit4] 2> =09at org.eclipse.jetty.server.Server.handle(Server.java:5= 34) [junit4] 2> =09at org.eclipse.jetty.server.HttpChannel.handle(HttpChan= nel.java:320) [junit4] 2> =09at org.eclipse.jetty.server.HttpConnection.onFillable(H= ttpConnection.java:251) [junit4] 2> =09at org.eclipse.jetty.io.AbstractConnection$ReadCallback= .succeeded(AbstractConnection.java:283) [junit4] 2> =09at org.eclipse.jetty.io.FillInterest.fillable(FillInter= est.java:108) [junit4] 2> =09at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(Sel= ectChannelEndPoint.java:93) [junit4] 2> =09at org.eclipse.jetty.util.thread.strategy.ExecuteProduc= eConsume.executeProduceConsume(ExecuteProduceConsume.java:303) [junit4] 2> =09at org.eclipse.jetty.util.thread.strategy.ExecuteProduc= eConsume.produceConsume(ExecuteProduceConsume.java:148) [junit4] 2> =09at org.eclipse.jetty.util.thread.strategy.ExecuteProduc= eConsume.run(ExecuteProduceConsume.java:136) [junit4] 2> =09at org.eclipse.jetty.util.thread.QueuedThreadPool.runJo= b(QueuedThreadPool.java:671) [junit4] 2> =09at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run= (QueuedThreadPool.java:589) [junit4] 2> =09at java.lang.Thread.run(Thread.java:748) [junit4] 2> Caused by: java.lang.IllegalArgumentException: userName is= NULL, empty or contains a '&' [junit4] 2> =09at org.apache.hadoop.security.authentication.util.AuthT= oken.checkForIllegalArgument(AuthToken.java:87) [junit4] 2> =09at org.apache.hadoop.security.authentication.util.AuthT= oken.(AuthToken.java:70) [junit4] 2> =09at org.apache.hadoop.security.authentication.server.Aut= henticationToken.(AuthenticationToken.java:58) [junit4] 2> =09at org.apache.solr.security.HttpParamDelegationTokenPlu= gin$HttpParamDelegationTokenAuthenticationHandler$HttpParamAuthenticationHa= ndler.authenticate(HttpParamDelegationTokenPlugin.java:213) [junit4] 2> =09at org.apache.hadoop.security.token.delegation.web.Dele= gationTokenAuthenticationHandler.authenticate(DelegationTokenAuthentication= Handler.java:348) [junit4] 2> =09at org.apache.solr.security.RequestContinuesRecorderAut= henticationHandler.authenticate(RequestContinuesRecorderAuthenticationHandl= er.java:69) [junit4] 2> =09at org.apache.hadoop.security.authentication.server.Aut= henticationFilter.doFilter(AuthenticationFilter.java:518) [junit4] 2> =09at org.apache.solr.security.DelegationTokenKerberosFilt= er.doFilter(DelegationTokenKerberosFilter.java:134) [junit4] 2> =09at org.apache.solr.security.HttpParamDelegationTokenPlu= gin$HttpParamToRequestFilter.doFilter(HttpParamDelegationTokenPlugin.java:2= 45) [junit4] 2> =09at org.apache.solr.security.KerberosPlugin.doAuthentica= te(KerberosPlugin.java:243) [junit4] 2> =09at org.apache.solr.servlet.SolrDispatchFilter.authentic= ateRequest(SolrDispatchFilter.java:451) [junit4] 2> =09... 26 more [junit4] 2> 287229 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyNullProxyUser-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 #= ##Ending testProxyNullProxyUser [junit4] 2> 287246 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyValidateHost-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 ##= #Starting testProxyValidateHost [junit4] 2> 287248 INFO (qtp10807214-3738) [n:127.0.0.1:39099_solr = ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params= doAs=3Dbar&action=3DLIST&wt=3Djavabin&version=3D2 and sendToOCPQueue=3Dtru= e [junit4] 2> 287248 INFO (qtp10807214-3738) [n:127.0.0.1:39099_solr = ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/collections par= ams=3D{doAs=3Dbar&action=3DLIST&wt=3Djavabin&version=3D2} status=3D0 QTime= =3D0 [junit4] 2> 287248 WARN (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyValidateHost-seed#[70A943F10BDA666F]) [ ] o.a.h.c.p.ResponseProce= ssCookies Invalid cookie header: "Set-Cookie: hadoop.auth=3D"u=3DlocalHostA= nyGroup&p=3DlocalHostAnyGroup&t=3Dtest&e=3D1513653088248&s=3DgmNtKT+BMpHKdy= EbCldrdGvPngw=3D"; Path=3D/; Domain=3D127.0.0.1; Expires=3D=C3=BEri., 19-de= s.-2017 03:11:28 GMT; HttpOnly". Invalid 'expires' attribute: =C3=BEri., 19= -des.-2017 03:11:28 GMT [junit4] 2> 287248 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyValidateHost-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 ##= #Ending testProxyValidateHost [junit4] 2> 287267 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyInvalidGroup-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 ##= #Starting testProxyInvalidGroup [junit4] 2> 287278 WARN (qtp10807214-3736) [ ] o.a.h.s.ShellBasedU= nixGroupsMapping got exception trying to get groups for user bar: id: =C3= =A2=C2=80=C2=98bar=C3=A2=C2=80=C2=99: no such user [junit4] 2> id: =C3=A2=C2=80=C2=98bar=C3=A2=C2=80=C2=99: no such user [junit4] 2>=20 [junit4] 2> 287280 WARN (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyInvalidGroup-seed#[70A943F10BDA666F]) [ ] o.a.h.c.p.ResponseProce= ssCookies Invalid cookie header: "Set-Cookie: hadoop.auth=3D"u=3DbogusGroup= &p=3DbogusGroup&t=3Dtest&e=3D1513653088268&s=3DEdzbzY8ka1K+3fSUtBrDRb+htP8= =3D"; Path=3D/; Domain=3D127.0.0.1; Expires=3D=C3=BEri., 19-des.-2017 03:11= :28 GMT; HttpOnly". Invalid 'expires' attribute: =C3=BEri., 19-des.-2017 03= :11:28 GMT [junit4] 2> 287280 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyInvalidGroup-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 ##= #Ending testProxyInvalidGroup [junit4] 2> 287297 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyValidateAnyHostAnyUser-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTes= tCaseJ4 ###Starting testProxyValidateAnyHostAnyUser [junit4] 2> 287298 INFO (qtp10807214-3724) [n:127.0.0.1:39099_solr = ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params= doAs=3Dbar&action=3DLIST&wt=3Djavabin&version=3D2 and sendToOCPQueue=3Dtru= e [junit4] 2> 287298 INFO (qtp10807214-3724) [n:127.0.0.1:39099_solr = ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/collections par= ams=3D{doAs=3Dbar&action=3DLIST&wt=3Djavabin&version=3D2} status=3D0 QTime= =3D0 [junit4] 2> 287298 WARN (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyValidateAnyHostAnyUser-seed#[70A943F10BDA666F]) [ ] o.a.h.c.p.Res= ponseProcessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=3D"u=3D= anyHostAnyUser&p=3DanyHostAnyUser&t=3Dtest&e=3D1513653088298&s=3DSUFGhZQF3t= BrFnNPd0FBAuikL9Y=3D"; Path=3D/; Domain=3D127.0.0.1; Expires=3D=C3=BEri., 1= 9-des.-2017 03:11:28 GMT; HttpOnly". Invalid 'expires' attribute: =C3=BEri.= , 19-des.-2017 03:11:28 GMT [junit4] 2> 287299 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyValidateAnyHostAnyUser-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTes= tCaseJ4 ###Ending testProxyValidateAnyHostAnyUser [junit4] 2> 287328 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stForwarding-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 ###Starti= ng testForwarding [junit4] 2> 287329 INFO (zkConnectionManagerCallback-900-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 287543 INFO (zkConnectionManagerCallback-903-thread-1) [ = ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 287544 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stForwarding-seed#[70A943F10BDA666F]) [ ] o.a.s.c.c.ZkStateReader Update= d live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 287544 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stForwarding-seed#[70A943F10BDA666F]) [ ] o.a.s.c.s.i.ZkClientClusterSta= teProvider Cluster at 127.0.0.1:33473/solr ready [junit4] 2> 287546 INFO (qtp10807214-3738) [n:127.0.0.1:39099_solr = ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with para= ms pullReplicas=3D0&replicationFactor=3D1&collection.configName=3Dconf1&max= ShardsPerNode=3D1&name=3DforwardingCollection&nrtReplicas=3D1&action=3DCREA= TE&numShards=3D1&tlogReplicas=3D0&wt=3Djavabin&version=3D2 and sendToOCPQue= ue=3Dtrue [junit4] 2> 287551 INFO (OverseerThreadFactory-1435-thread-1-processi= ng-n:127.0.0.1:39099_solr) [n:127.0.0.1:39099_solr ] o.a.s.c.CreateColle= ctionCmd Create collection forwardingCollection [junit4] 2> 287655 INFO (OverseerStateUpdate-99196409440436230-127.0.= 0.1:39099_solr-n_0000000000) [n:127.0.0.1:39099_solr ] o.a.s.c.o.SliceMu= tator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"forwardingCollection", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"forwardingCollection_shard1_replica_n1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:38887/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"}=20 [junit4] 2> 287857 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr = ] o.a.s.h.a.CoreAdminOperation core create command qt=3D/admin/cores&coreN= odeName=3Dcore_node2&collection.configName=3Dconf1&newCollection=3Dtrue&nam= e=3DforwardingCollection_shard1_replica_n1&action=3DCREATE&numShards=3D1&co= llection=3DforwardingCollection&shard=3Dshard1&wt=3Djavabin&version=3D2&rep= licaType=3DNRT [junit4] 2> 287858 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr = ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 214= 7483647 transient cores [junit4] 2> 287960 INFO (zkCallback-888-thread-1-processing-n:127.0.0= .1:38887_solr) [n:127.0.0.1:38887_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/forwardingCollection/state.json] for collection [forwardingC= ollection] has occurred - updating... (live nodes size: [2]) [junit4] 2> 287961 INFO (zkCallback-888-thread-2-processing-n:127.0.0= .1:38887_solr) [n:127.0.0.1:38887_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/forwardingCollection/state.json] for collection [forwardingC= ollection] has occurred - updating... (live nodes size: [2]) [junit4] 2> 288876 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0 [junit4] 2> 288898 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.s.IndexSchema [forwardingCollection_shard1_replica_n1] Sche= ma name=3Dtest [junit4] 2> 288969 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 288978 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.c.CoreContainer Creating SolrCore 'forwardingCollection_sha= rd1_replica_n1' using configuration from collection forwardingCollection, t= rusted=3Dtrue [junit4] 2> 288978 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38887.solr.cor= e.forwardingCollection.shard1.replica_n1' (registry 'solr.core.forwardingCo= llection.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.Jmx= MBeanServer@13c7785 [junit4] 2> 288978 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 288978 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.c.SolrCore [[forwardingCollection_shard1_replica_n1] ] Open= ing new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/bui= ld/solr-core/test/J2/temp/solr.cloud.TestSolrCloudWithSecureImpersonation_7= 0A943F10BDA666F-001/tempDir-001/node2/forwardingCollection_shard1_replica_n= 1], dataDir=3D[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/sol= r-core/test/J2/temp/solr.cloud.TestSolrCloudWithSecureImpersonation_70A943F= 10BDA666F-001/tempDir-001/node2/./forwardingCollection_shard1_replica_n1/da= ta/] [junit4] 2> 288980 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.ap= ache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMerge= Size=3D1677721, mergeFactor=3D40, maxMergeSize=3D2147483648, maxMergeSizeFo= rForcedMerge=3D9223372036854775807, calibrateSizeByDeletes=3Dtrue, maxMerge= Docs=3D2147483647, maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio= =3D1.0] [junit4] 2> 289030 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.= solr.update.UpdateLog [junit4] 2> 289030 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=3D defaultSyncL= evel=3DFLUSH numRecordsToKeep=3D100 maxNumLogsToKeep=3D10 numVersionBuckets= =3D65536 [junit4] 2> 289032 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 289032 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 289033 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.ap= ache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=3D1= 2, maxMergeAtOnceExplicit=3D48, maxMergedSegmentMB=3D45.9970703125, floorSe= gmentMB=3D0.9794921875, forceMergeDeletesPctAllowed=3D23.59288150028076, se= gmentsPerTier=3D44.0, maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRati= o=3D0.0 [junit4] 2> 289033 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@765ad2[forwardingColl= ection_shard1_replica_n1] main] [junit4] 2> 289035 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers [junit4] 2> 289060 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.s.DirectSolrSpellChecker init: {name=3Ddirect,classname=3DD= irectSolrSpellChecker,field=3Dlowerfilt,minQueryLength=3D3} [junit4] 2> 289149 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 289149 INFO (searcherExecutor-1440-thread-1-processing-n:= 127.0.0.1:38887_solr x:forwardingCollection_shard1_replica_n1 s:shard1 c:fo= rwardingCollection r:core_node2) [n:127.0.0.1:38887_solr c:forwardingCollec= tion s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1] o.a.s.= h.c.SpellCheckComponent Loading spell index for spellchecker: default [junit4] 2> 289150 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent u= pdates, using new clock 1587142553922174976 [junit4] 2> 289150 INFO (searcherExecutor-1440-thread-1-processing-n:= 127.0.0.1:38887_solr x:forwardingCollection_shard1_replica_n1 s:shard1 c:fo= rwardingCollection r:core_node2) [n:127.0.0.1:38887_solr c:forwardingCollec= tion s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1] o.a.s.= h.c.SpellCheckComponent Loading spell index for spellchecker: direct [junit4] 2> 289150 INFO (searcherExecutor-1440-thread-1-processing-n:= 127.0.0.1:38887_solr x:forwardingCollection_shard1_replica_n1 s:shard1 c:fo= rwardingCollection r:core_node2) [n:127.0.0.1:38887_solr c:forwardingCollec= tion s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1] o.a.s.= h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak [junit4] 2> 289150 INFO (searcherExecutor-1440-thread-1-processing-n:= 127.0.0.1:38887_solr x:forwardingCollection_shard1_replica_n1 s:shard1 c:fo= rwardingCollection r:core_node2) [n:127.0.0.1:38887_solr c:forwardingCollec= tion s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1] o.a.s.= h.c.SpellCheckComponent Loading spell index for spellchecker: multipleField= s [junit4] 2> 289150 INFO (searcherExecutor-1440-thread-1-processing-n:= 127.0.0.1:38887_solr x:forwardingCollection_shard1_replica_n1 s:shard1 c:fo= rwardingCollection r:core_node2) [n:127.0.0.1:38887_solr c:forwardingCollec= tion s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1] o.a.s.= h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler [junit4] 2> 289150 INFO (searcherExecutor-1440-thread-1-processing-n:= 127.0.0.1:38887_solr x:forwardingCollection_shard1_replica_n1 s:shard1 c:fo= rwardingCollection r:core_node2) [n:127.0.0.1:38887_solr c:forwardingCollec= tion s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1] o.a.s.= h.c.SpellCheckComponent Loading spell index for spellchecker: external [junit4] 2> 289150 INFO (searcherExecutor-1440-thread-1-processing-n:= 127.0.0.1:38887_solr x:forwardingCollection_shard1_replica_n1 s:shard1 c:fo= rwardingCollection r:core_node2) [n:127.0.0.1:38887_solr c:forwardingCollec= tion s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1] o.a.s.= h.c.SpellCheckComponent Loading spell index for spellchecker: freq [junit4] 2> 289150 INFO (searcherExecutor-1440-thread-1-processing-n:= 127.0.0.1:38887_solr x:forwardingCollection_shard1_replica_n1 s:shard1 c:fo= rwardingCollection r:core_node2) [n:127.0.0.1:38887_solr c:forwardingCollec= tion s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1] o.a.s.= h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn [junit4] 2> 289150 INFO (searcherExecutor-1440-thread-1-processing-n:= 127.0.0.1:38887_solr x:forwardingCollection_shard1_replica_n1 s:shard1 c:fo= rwardingCollection r:core_node2) [n:127.0.0.1:38887_solr c:forwardingCollec= tion s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1] o.a.s.= h.c.SpellCheckComponent Loading spell index for spellchecker: perDict [junit4] 2> 289151 INFO (searcherExecutor-1440-thread-1-processing-n:= 127.0.0.1:38887_solr x:forwardingCollection_shard1_replica_n1 s:shard1 c:fo= rwardingCollection r:core_node2) [n:127.0.0.1:38887_solr c:forwardingCollec= tion s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1] o.a.s.= c.SolrCore [forwardingCollection_shard1_replica_n1] Registered new searcher= Searcher@765ad2[forwardingCollection_shard1_replica_n1] main{ExitableDirec= toryReader(UninvertingDirectoryReader())} [junit4] 2> 289152 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to conti= nue. [junit4] 2> 289152 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try = and sync [junit4] 2> 289152 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:38887/solr= /forwardingCollection_shard1_replica_n1/ [junit4] 2> 289152 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 289152 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:38887/solr/forwardingCollec= tion_shard1_replica_n1/ has no replicas [junit4] 2> 289152 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participati= ng in election, clear LIR [junit4] 2> 289154 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://12= 7.0.0.1:38887/solr/forwardingCollection_shard1_replica_n1/ shard1 [junit4] 2> 289254 INFO (zkCallback-888-thread-1-processing-n:127.0.0= .1:38887_solr) [n:127.0.0.1:38887_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/forwardingCollection/state.json] for collection [forwardingC= ollection] has occurred - updating... (live nodes size: [2]) [junit4] 2> 289254 INFO (zkCallback-888-thread-2-processing-n:127.0.0= .1:38887_solr) [n:127.0.0.1:38887_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/forwardingCollection/state.json] for collection [forwardingC= ollection] has occurred - updating... (live nodes size: [2]) [junit4] 2> 289304 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 289305 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cores pa= rams=3D{qt=3D/admin/cores&coreNodeName=3Dcore_node2&collection.configName= =3Dconf1&newCollection=3Dtrue&name=3DforwardingCollection_shard1_replica_n1= &action=3DCREATE&numShards=3D1&collection=3DforwardingCollection&shard=3Dsh= ard1&wt=3Djavabin&version=3D2&replicaType=3DNRT} status=3D0 QTime=3D1447 [junit4] 2> 289306 WARN (httpShardExecutor-1431-thread-1-processing-n= :127.0.0.1:39099_solr [http:////127.0.0.1:38887//solr] http:////127.0.0.1:3= 8887//solr) [n:127.0.0.1:39099_solr ] o.a.h.c.p.ResponseProcessCookies I= nvalid cookie header: "Set-Cookie: hadoop.auth=3D"u=3D$&p=3D$&t=3Dtest&e=3D= 1513653088858&s=3DZng9HaAjALmr3QXf/y+WkXeHAS0=3D"; Path=3D/; Domain=3D127.0= .0.1; Expires=3D=C3=BEri., 19-des.-2017 03:11:28 GMT; HttpOnly". Invalid 'e= xpires' attribute: =C3=BEri., 19-des.-2017 03:11:28 GMT [junit4] 2> 289308 INFO (qtp10807214-3738) [n:127.0.0.1:39099_solr = ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at= most 30 seconds. Check all shard replicas [junit4] 2> 289408 INFO (zkCallback-888-thread-2-processing-n:127.0.0= .1:38887_solr) [n:127.0.0.1:38887_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/forwardingCollection/state.json] for collection [forwardingC= ollection] has occurred - updating... (live nodes size: [2]) [junit4] 2> 289408 INFO (zkCallback-888-thread-1-processing-n:127.0.0= .1:38887_solr) [n:127.0.0.1:38887_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/forwardingCollection/state.json] for collection [forwardingC= ollection] has occurred - updating... (live nodes size: [2]) [junit4] 2> 289553 INFO (OverseerCollectionConfigSetProcessor-9919640= 9440436230-127.0.0.1:39099_solr-n_0000000000) [n:127.0.0.1:39099_solr ] = o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work= /qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKee= per [junit4] 2> 290309 INFO (qtp10807214-3738) [n:127.0.0.1:39099_solr = ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/collections par= ams=3D{pullReplicas=3D0&replicationFactor=3D1&collection.configName=3Dconf1= &maxShardsPerNode=3D1&name=3DforwardingCollection&nrtReplicas=3D1&action=3D= CREATE&numShards=3D1&tlogReplicas=3D0&wt=3Djavabin&version=3D2} status=3D0 = QTime=3D2763 [junit4] 2> 290310 WARN (TEST-TestSolrCloudWithSecureImpersonation.te= stForwarding-seed#[70A943F10BDA666F]) [ ] o.a.h.c.p.ResponseProcessCooki= es Invalid cookie header: "Set-Cookie: hadoop.auth=3D"u=3Duser&p=3Duser&t= =3Dtest&e=3D1513653088546&s=3DCI1zg3ggLj1ARNpgOCgdeiILBTo=3D"; Path=3D/; Do= main=3D127.0.0.1; Expires=3D=C3=BEri., 19-des.-2017 03:11:28 GMT; HttpOnly"= . Invalid 'expires' attribute: =C3=BEri., 19-des.-2017 03:11:28 GMT [junit4] 2> 290310 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stForwarding-seed#[70A943F10BDA666F]) [ ] o.a.s.c.AbstractDistribZkTestB= ase Wait for recoveries to finish - collection: forwardingCollection failOn= Timeout:true timeout (sec):100 [junit4] 2> 290310 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stForwarding-seed#[70A943F10BDA666F]) [ ] o.a.s.c.AbstractDistribZkTestB= ase Recoveries finished - collection: forwardingCollection [junit4] 2> 290313 INFO (qtp10807214-3730) [n:127.0.0.1:39099_solr = ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 214= 7483647 transient cores [junit4] 2> 290315 INFO (qtp31948827-3739) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.c.S.Request [forwardingCollection_shard1_replica_n1] webap= p=3D/solr path=3D/select params=3D{q=3D*:*&wt=3Djavabin&version=3D2} hits= =3D0 status=3D0 QTime=3D0 [junit4] 2> 290316 WARN (qtp10807214-3730) [n:127.0.0.1:39099_solr = ] o.a.h.c.p.ResponseProcessCookies Invalid cookie header: "Set-Cookie: had= oop.auth=3D"u=3D$&p=3D$&t=3Dtest&e=3D1513653091315&s=3Dx0jxP+e+UaKhQdQ6EpC4= n3x21hc=3D"; Path=3D/; Domain=3D127.0.0.1; Expires=3D=C3=BEri., 19-des.-201= 7 03:11:31 GMT; HttpOnly". Invalid 'expires' attribute: =C3=BEri., 19-des.-= 2017 03:11:31 GMT [junit4] 2> 290316 WARN (TEST-TestSolrCloudWithSecureImpersonation.te= stForwarding-seed#[70A943F10BDA666F]) [ ] o.a.h.c.p.ResponseProcessCooki= es Invalid cookie header: "Set-Cookie: hadoop.auth=3D"u=3Duser&p=3Duser&t= =3Dtest&e=3D1513653091314&s=3Dx98n5MXY/DRG4QQgpGB0xA7QfaY=3D"; Path=3D/; Do= main=3D127.0.0.1; Expires=3D=C3=BEri., 19-des.-2017 03:11:31 GMT; HttpOnly"= . Invalid 'expires' attribute: =C3=BEri., 19-des.-2017 03:11:31 GMT [junit4] 2> 290317 WARN (TEST-TestSolrCloudWithSecureImpersonation.te= stForwarding-seed#[70A943F10BDA666F]) [ ] o.a.h.c.p.ResponseProcessCooki= es Invalid cookie header: "Set-Cookie: hadoop.auth=3D"u=3D$&p=3D$&t=3Dtest&= e=3D1513653091315&s=3Dx0jxP+e+UaKhQdQ6EpC4n3x21hc=3D"; Path=3D/; Domain=3D1= 27.0.0.1; Expires=3D=C3=BEri., 19-des.-2017 03:11:31 GMT; HttpOnly". Invali= d 'expires' attribute: =C3=BEri., 19-des.-2017 03:11:31 GMT [junit4] 2> 290319 INFO (qtp31948827-3735) [n:127.0.0.1:38887_solr c:= forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_re= plica_n1] o.a.s.c.S.Request [forwardingCollection_shard1_replica_n1] webap= p=3D/solr path=3D/select params=3D{q=3D*:*&wt=3Djavabin&version=3D2} hits= =3D0 status=3D0 QTime=3D0 [junit4] 2> 290319 WARN (TEST-TestSolrCloudWithSecureImpersonation.te= stForwarding-seed#[70A943F10BDA666F]) [ ] o.a.h.c.p.ResponseProcessCooki= es Invalid cookie header: "Set-Cookie: hadoop.auth=3D"u=3Duser&p=3Duser&t= =3Dtest&e=3D1513653091320&s=3DOtbvv2Ex4dvVQAv1TscljPpweSg=3D"; Path=3D/; Do= main=3D127.0.0.1; Expires=3D=C3=BEri., 19-des.-2017 03:11:31 GMT; HttpOnly"= . Invalid 'expires' attribute: =C3=BEri., 19-des.-2017 03:11:31 GMT [junit4] 2> 290320 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stForwarding-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 ###Ending= testForwarding [junit4] 2> 290343 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyInvalidProxyUser-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ= 4 ###Starting testProxyInvalidProxyUser [junit4] 2> 290347 WARN (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyInvalidProxyUser-seed#[70A943F10BDA666F]) [ ] o.a.h.c.p.ResponseP= rocessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=3D"u=3Dbar&p= =3Dbar&t=3Dtest&e=3D1513653091346&s=3DCt8FtP7VBGJhvuqcaJHjKdNCeKY=3D"; Path= =3D/; Domain=3D127.0.0.1; Expires=3D=C3=BEri., 19-des.-2017 03:11:31 GMT; H= ttpOnly". Invalid 'expires' attribute: =C3=BEri., 19-des.-2017 03:11:31 GMT [junit4] 2> 290347 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyInvalidProxyUser-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ= 4 ###Ending testProxyInvalidProxyUser [junit4] 2> 290364 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyNoConfigGroups-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 = ###Starting testProxyNoConfigGroups [junit4] 2> 290366 WARN (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyNoConfigGroups-seed#[70A943F10BDA666F]) [ ] o.a.h.c.p.ResponsePro= cessCookies Invalid cookie header: "Set-Cookie: hadoop.auth=3D"u=3DnoGroups= &p=3DnoGroups&t=3Dtest&e=3D1513653091365&s=3Dk13Nezi0OZ9Ox5IHIU/4Dn154MQ=3D= "; Path=3D/; Domain=3D127.0.0.1; Expires=3D=C3=BEri., 19-des.-2017 03:11:31= GMT; HttpOnly". Invalid 'expires' attribute: =C3=BEri., 19-des.-2017 03:11= :31 GMT [junit4] 2> 290366 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyNoConfigGroups-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 = ###Ending testProxyNoConfigGroups [junit4] 2> 290398 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyNoConfigHosts-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 #= ##Starting testProxyNoConfigHosts [junit4] 2> 290400 WARN (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyNoConfigHosts-seed#[70A943F10BDA666F]) [ ] o.a.h.c.p.ResponseProc= essCookies Invalid cookie header: "Set-Cookie: hadoop.auth=3D"u=3DnoHosts&p= =3DnoHosts&t=3Dtest&e=3D1513653091399&s=3Dsfivld+AVP55YwIj+sjumZ2eHB0=3D"; = Path=3D/; Domain=3D127.0.0.1; Expires=3D=C3=BEri., 19-des.-2017 03:11:31 GM= T; HttpOnly". Invalid 'expires' attribute: =C3=BEri., 19-des.-2017 03:11:31= GMT [junit4] 2> 290400 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyNoConfigHosts-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 #= ##Ending testProxyNoConfigHosts [junit4] 2> 290425 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyUnknownRemote-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 #= ##Starting testProxyUnknownRemote [junit4] 2> 306994 WARN (jetty-launcher-872-thread-1-SendThread(127.0= .0.1:33473)) [n:127.0.0.1:39099_solr ] o.a.z.ClientCnxn Client session t= imed out, have not heard from server in 20022ms for sessionid 0x1606a9bdbb1= 0007 [junit4] 2> 306994 WARN (jetty-launcher-872-thread-1-SendThread(127.0= .0.1:33473)) [n:127.0.0.1:39099_solr ] o.a.z.ClientCnxn Client session t= imed out, have not heard from server in 16681ms for sessionid 0x1606a9bdbb1= 0006 [junit4] 2> 306994 WARN (jetty-launcher-872-thread-2-SendThread(127.0= .0.1:33473)) [n:127.0.0.1:38887_solr ] o.a.z.ClientCnxn Client session t= imed out, have not heard from server in 20022ms for sessionid 0x1606a9bdbb1= 0008 [junit4] 2> 306994 WARN (jetty-launcher-872-thread-2-SendThread(127.0= .0.1:33473)) [n:127.0.0.1:38887_solr ] o.a.z.ClientCnxn Client session t= imed out, have not heard from server in 17586ms for sessionid 0x1606a9bdbb1= 0005 [junit4] 2> 306995 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ = ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from = client sessionid 0x1606a9bdbb10007, likely client has closed socket [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOSe= rverCnxn.java:239) [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxnFactory.run= (NIOServerCnxnFactory.java:203) [junit4] 2> =09at java.lang.Thread.run(Thread.java:748) [junit4] 2> 306996 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ = ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from = client sessionid 0x1606a9bdbb10008, likely client has closed socket [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOSe= rverCnxn.java:239) [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxnFactory.run= (NIOServerCnxnFactory.java:203) [junit4] 2> =09at java.lang.Thread.run(Thread.java:748) [junit4] 2> 306996 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ = ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from = client sessionid 0x1606a9bdbb10005, likely client has closed socket [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOSe= rverCnxn.java:239) [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxnFactory.run= (NIOServerCnxnFactory.java:203) [junit4] 2> =09at java.lang.Thread.run(Thread.java:748) [junit4] 2> 306996 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ = ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from = client sessionid 0x1606a9bdbb10006, likely client has closed socket [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOSe= rverCnxn.java:239) [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxnFactory.run= (NIOServerCnxnFactory.java:203) [junit4] 2> =09at java.lang.Thread.run(Thread.java:748) [junit4] 2> 306998 WARN (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyUnknownRemote-seed#[70A943F10BDA666F]) [ ] o.a.h.c.p.ResponseProc= essCookies Invalid cookie header: "Set-Cookie: hadoop.auth=3D"u=3DlocalHost= AnyGroup&p=3DlocalHostAnyGroup&t=3Dtest&e=3D1513653091426&s=3DvRN22RgiQSU4O= P/oMmZCiHsEPNc=3D"; Path=3D/; Domain=3D127.0.0.1; Expires=3D=C3=BEri., 19-d= es.-2017 03:11:31 GMT; HttpOnly". Invalid 'expires' attribute: =C3=BEri., 1= 9-des.-2017 03:11:31 GMT [junit4] 2> 306998 INFO (TEST-TestSolrCloudWithSecureImpersonation.te= stProxyUnknownRemote-seed#[70A943F10BDA666F]) [ ] o.a.s.SolrTestCaseJ4 #= ##Ending testProxyUnknownRemote [junit4] 2> 307095 INFO (jetty-launcher-872-thread-1-EventThread) [n:= 127.0.0.1:39099_solr ] o.a.c.f.s.ConnectionStateManager State change: SU= SPENDED [junit4] 2> 307095 WARN (zkConnectionManagerCallback-903-thread-1) [ = ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.Conne= ctionManager@243267 name: ZooKeeperConnection Watcher:127.0.0.1:33473/solr = got event WatchedEvent state:Disconnected type:None path:null path: null ty= pe: None [junit4] 2> 307095 WARN (zkConnectionManagerCallback-891-thread-1-pro= cessing-n:127.0.0.1:39099_solr) [n:127.0.0.1:39099_solr ] o.a.s.c.c.Conn= ectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@170c71= b name: ZooKeeperConnection Watcher:127.0.0.1:33473/solr got event WatchedE= vent state:Disconnected type:None path:null path: null type: None [junit4] 2> 307095 WARN (zkConnectionManagerCallback-891-thread-1-pro= cessing-n:127.0.0.1:39099_solr) [n:127.0.0.1:39099_solr ] o.a.s.c.c.Conn= ectionManager zkClient has disconnected [junit4] 2> 307096 WARN (zkConnectionManagerCallback-889-thread-1-pro= cessing-n:127.0.0.1:38887_solr) [n:127.0.0.1:38887_solr ] o.a.s.c.c.Conn= ectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@1edcf4= 3 name: ZooKeeperConnection Watcher:127.0.0.1:33473/solr got event WatchedE= vent state:Disconnected type:None path:null path: null type: None [junit4] 2> 307096 WARN (zkConnectionManagerCallback-889-thread-1-pro= cessing-n:127.0.0.1:38887_solr) [n:127.0.0.1:38887_solr ] o.a.s.c.c.Conn= ectionManager zkClient has disconnected [junit4] 2> 307104 INFO (jetty-closer-873-thread-2) [ ] o.e.j.s.Ab= stractConnector Stopped ServerConnector@11f1670{HTTP/1.1,[http/1.1]}{127.0.= 0.1:0} [junit4] 2> 307104 INFO (jetty-closer-873-thread-2) [ ] o.a.s.c.Co= reContainer Shutting down CoreContainer instance=3D18945451 [junit4] 2> 307104 INFO (jetty-closer-873-thread-2) [ ] o.a.s.m.So= lrMetricManager Closing metric reporters for registry=3Dsolr.node, tag=3Dnu= ll [junit4] 2> 307105 INFO (jetty-closer-873-thread-2) [ ] o.a.s.m.r.= SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmx= Reporter@14179a3: rootName =3D solr_38887, domain =3D solr.node, service ur= l =3D null, agent id =3D null] for registry solr.node / com.codahale.metric= s.MetricRegistry@188ec18 [junit4] 2> 307105 INFO (jetty-closer-873-thread-1) [ ] o.e.j.s.Ab= stractConnector Stopped ServerConnector@17b8a4c{HTTP/1.1,[http/1.1]}{127.0.= 0.1:0} [junit4] 2> 307105 INFO (jetty-closer-873-thread-1) [ ] o.a.s.c.Co= reContainer Shutting down CoreContainer instance=3D28527442 [junit4] 2> 307105 INFO (jetty-closer-873-thread-1) [ ] o.a.s.m.So= lrMetricManager Closing metric reporters for registry=3Dsolr.node, tag=3Dnu= ll [junit4] 2> 307105 INFO (jetty-closer-873-thread-1) [ ] o.a.s.m.r.= SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmx= Reporter@12acd42: rootName =3D solr_39099, domain =3D solr.node, service ur= l =3D null, agent id =3D null] for registry solr.node / com.codahale.metric= s.MetricRegistry@16d4ba [junit4] 2> 307114 INFO (jetty-closer-873-thread-2) [ ] o.a.s.m.So= lrMetricManager Closing metric reporters for registry=3Dsolr.jvm, tag=3Dnul= l [junit4] 2> 307114 INFO (jetty-closer-873-thread-2) [ ] o.a.s.m.r.= SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmx= Reporter@7436b3: rootName =3D solr_38887, domain =3D solr.jvm, service url = =3D null, agent id =3D null] for registry solr.jvm / com.codahale.metrics.M= etricRegistry@13653a8 [junit4] 2> 307115 INFO (jetty-closer-873-thread-1) [ ] o.a.s.m.So= lrMetricManager Closing metric reporters for registry=3Dsolr.jvm, tag=3Dnul= l [junit4] 2> 307115 INFO (jetty-closer-873-thread-1) [ ] o.a.s.m.r.= SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmx= Reporter@ada826: rootName =3D solr_39099, domain =3D solr.jvm, service url = =3D null, agent id =3D null] for registry solr.jvm / com.codahale.metrics.M= etricRegistry@13653a8 [junit4] 2> 307120 INFO (jetty-closer-873-thread-2) [ ] o.a.s.m.So= lrMetricManager Closing metric reporters for registry=3Dsolr.jetty, tag=3Dn= ull [junit4] 2> 307120 INFO (jetty-closer-873-thread-2) [ ] o.a.s.m.r.= SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmx= Reporter@3fb8ba: rootName =3D solr_38887, domain =3D solr.jetty, service ur= l =3D null, agent id =3D null] for registry solr.jetty / com.codahale.metri= cs.MetricRegistry@a4e093 [junit4] 2> 307121 INFO (jetty-closer-873-thread-1) [ ] o.a.s.m.So= lrMetricManager Closing metric reporters for registry=3Dsolr.jetty, tag=3Dn= ull [junit4] 2> 307121 INFO (jetty-closer-873-thread-1) [ ] o.a.s.m.r.= SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmx= Reporter@4fc302: rootName =3D solr_39099, domain =3D solr.jetty, service ur= l =3D null, agent id =3D null] for registry solr.jetty / com.codahale.metri= cs.MetricRegistry@a4e093 [junit4] 2> 308309 WARN (jetty-launcher-872-thread-2-SendThread(127.0= .0.1:33473)) [n:127.0.0.1:38887_solr ] o.a.z.ClientCnxn Unable to reconn= ect to ZooKeeper service, session 0x1606a9bdbb10008 has expired [junit4] 2> 308475 INFO (zkConnectionManagerCallback-889-thread-1-pro= cessing-n:127.0.0.1:38887_solr) [n:127.0.0.1:38887_solr ] o.a.s.c.c.Conn= ectionManager zkClient has connected [junit4] 2> 308477 INFO (jetty-closer-873-thread-2) [ ] o.a.s.c.Zk= Controller Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:38887_sol= r [junit4] 2> 308477 INFO (jetty-closer-873-thread-2) [ ] o.a.s.m.So= lrMetricManager Closing metric reporters for registry=3Dsolr.cluster, tag= =3Dnull [junit4] 2> 308478 INFO (zkCallback-888-thread-1-processing-n:127.0.0= .1:38887_solr) [n:127.0.0.1:38887_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (2) -> (1) [junit4] 2> 308478 INFO (coreCloseExecutor-1445-thread-1) [n:127.0.0.= 1:38887_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingColle= ction_shard1_replica_n1] o.a.s.c.SolrCore [forwardingCollection_shard1_repl= ica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@a410b9 [junit4] 2> 308478 INFO (coreCloseExecutor-1445-thread-1) [n:127.0.0.= 1:38887_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingColle= ction_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters= for registry=3Dsolr.core.forwardingCollection.shard1.replica_n1, tag=3D107= 52185 [junit4] 2> 308478 INFO (coreCloseExecutor-1445-thread-1) [n:127.0.0.= 1:38887_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingColle= ction_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.ap= ache.solr.metrics.reporters.SolrJmxReporter@123ca7b: rootName =3D solr_3888= 7, domain =3D solr.core.forwardingCollection.shard1.replica_n1, service url= =3D null, agent id =3D null] for registry solr.core.forwardingCollection.s= hard1.replica_n1 / com.codahale.metrics.MetricRegistry@4c477f [junit4] 2> 308497 INFO (coreCloseExecutor-1445-thread-1) [n:127.0.0.= 1:38887_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingColle= ction_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters= for registry=3Dsolr.collection.forwardingCollection.shard1.leader, tag=3D1= 0752185 [junit4] 2> 308503 ERROR (Thread[Thread-874,5,TGRP-TestSolrCloudWithSe= cureImpersonation]) [n:127.0.0.1:38887_solr ] o.a.h.s.t.d.AbstractDelega= tionTokenSecretManager ExpiredTokenRemover received java.lang.InterruptedEx= ception: sleep interrupted [junit4] 2> 308513 INFO (jetty-closer-873-thread-2) [ ] o.e.j.s.h.= ContextHandler Stopped o.e.j.s.ServletContextHandler@5bc2c{/solr,null,UNAVA= ILABLE} [junit4] 2> 308829 WARN (jetty-launcher-872-thread-1-SendThread(127.0= .0.1:33473)) [n:127.0.0.1:39099_solr ] o.a.z.ClientCnxn Unable to reconn= ect to ZooKeeper service, session 0x1606a9bdbb10007 has expired [junit4] 2> 308923 INFO (zkConnectionManagerCallback-891-thread-1-pro= cessing-n:127.0.0.1:39099_solr) [n:127.0.0.1:39099_solr ] o.a.s.c.c.Conn= ectionManager zkClient has connected [junit4] 2> 308924 INFO (zkCallback-890-thread-1-processing-n:127.0.0= .1:39099_solr) [n:127.0.0.1:39099_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (2) -> (1) [junit4] 2> 308925 INFO (jetty-closer-873-thread-1) [ ] o.a.s.c.Zk= Controller Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:39099_sol= r [junit4] 2> 308925 INFO (jetty-closer-873-thread-1) [ ] o.a.s.m.So= lrMetricManager Closing metric reporters for registry=3Dsolr.cluster, tag= =3Dnull [junit4] 2> 308926 INFO (zkCallback-890-thread-1-processing-n:127.0.0= .1:39099_solr) [n:127.0.0.1:39099_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (1) -> (0) [junit4] 2> 308926 INFO (jetty-closer-873-thread-1) [ ] o.a.s.c.Ov= erseer Overseer (id=3D99196409440436230-127.0.0.1:39099_solr-n_0000000000) = closing [junit4] 2> 308927 INFO (OverseerStateUpdate-99196409440436230-127.0.= 0.1:39099_solr-n_0000000000) [n:127.0.0.1:39099_solr ] o.a.s.c.Overseer = Overseer Loop exiting : 127.0.0.1:39099_solr [junit4] 2> 308927 WARN (OverseerAutoScalingTriggerThread-99196409440= 436230-127.0.0.1:39099_solr-n_0000000000) [n:127.0.0.1:39099_solr ] o.a.= s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are close= d, exiting. [junit4] 2> 308929 ERROR (Thread[Thread-873,5,TGRP-TestSolrCloudWithSe= cureImpersonation]) [n:127.0.0.1:39099_solr ] o.a.h.s.t.d.AbstractDelega= tionTokenSecretManager ExpiredTokenRemover received java.lang.InterruptedEx= ception: sleep interrupted [junit4] 2> 308930 INFO (jetty-closer-873-thread-1) [ ] o.e.j.s.h.= ContextHandler Stopped o.e.j.s.ServletContextHandler@1875445{/solr,null,UNA= VAILABLE} [junit4] 2> 308930 ERROR (SUITE-TestSolrCloudWithSecureImpersonation-s= eed#[70A943F10BDA666F]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHan= dler is not registered, so ZooKeeper server won't take any action on ERROR = or SHUTDOWN server state changes [junit4] 2> 308931 INFO (SUITE-TestSolrCloudWithSecureImpersonation-s= eed#[70A943F10BDA666F]-worker) [ ] o.a.s.c.ZkTestServer connecting to 12= 7.0.0.1:33473 33473 [junit4] 2> 308980 INFO (Thread-856) [ ] o.a.s.c.ZkTestServer conn= ecting to 127.0.0.1:33473 33473 [junit4] 2> 308980 WARN (Thread-856) [ ] o.a.s.c.ZkTestServer Watc= h limit violations:=20 [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2>=20 [junit4] 2> =093=09/solr/aliases.json [junit4] 2> =093=09/solr/clusterprops.json [junit4] 2> =092=09/solr/security.json [junit4] 2>=20 [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2>=20 [junit4] 2> =095=09/solr/collections/forwardingCollection/state.json [junit4] 2> =094=09/solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMKeyIdRoot [junit4] 2> =093=09/solr/clusterstate.json [junit4] 2> =092=09/solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMMasterKeyRoo= t/DK_1 [junit4] 2> =092=09/solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMMasterKeyRoo= t/DK_3 [junit4] 2> =092=09/solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMMasterKeyRoo= t/DK_2 [junit4] 2> =092=09/solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMMasterKeyRoo= t/DK_4 [junit4] 2> =092=09/solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMSeqNumRoot [junit4] 2>=20 [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2>=20 [junit4] 2> =093=09/solr/live_nodes [junit4] 2> =093=09/solr/collections [junit4] 2> =092=09/solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMMasterKeyRoo= t [junit4] 2> =092=09/solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot [junit4] 2>=20 [junit4] 2> 308991 INFO (SUITE-TestSolrCloudWithSecureImpersonation-s= eed#[70A943F10BDA666F]-worker) [ ] o.a.s.SolrTestCaseJ4 ----------------= --------------------------------------- Done waiting for tracked resources = to be released [junit4] 2> Dec 18, 2017 5:11:49 PM com.carrotsearch.randomizedtesting= .ThreadLeakControl checkThreadLeaks [junit4] 2> WARNING: Will linger awaiting termination of 5 leaked thre= ad(s). [junit4] 2> Dec 18, 2017 5:12:10 PM com.carrotsearch.randomizedtesting= .ThreadLeakControl checkThreadLeaks [junit4] 2> SEVERE: 2 threads leaked from SUITE scope at org.apache.so= lr.cloud.TestSolrCloudWithSecureImpersonation:=20 [junit4] 2> 1) Thread[id=3D3777, name=3Djetty-launcher-872-thread-1= -EventThread, state=3DTIMED_WAITING, group=3DTGRP-TestSolrCloudWithSecureIm= personation] [junit4] 2> at sun.misc.Unsafe.park(Native Method) [junit4] 2> at java.util.concurrent.locks.LockSupport.parkNano= s(LockSupport.java:215) [junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchr= onizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1037) [junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchr= onizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1328) [junit4] 2> at java.util.concurrent.CountDownLatch.await(Count= DownLatch.java:277) [junit4] 2> at org.apache.curator.CuratorZookeeperClient.inter= nalBlockUntilConnectedOrTimedOut(CuratorZookeeperClient.java:323) [junit4] 2> at org.apache.curator.RetryLoop.callWithRetry(Retr= yLoop.java:105) [junit4] 2> at org.apache.curator.framework.imps.GetDataBuilde= rImpl.pathInForeground(GetDataBuilderImpl.java:288) [junit4] 2> at org.apache.curator.framework.imps.GetDataBuilde= rImpl.forPath(GetDataBuilderImpl.java:279) [junit4] 2> at org.apache.curator.framework.imps.GetDataBuilde= rImpl.forPath(GetDataBuilderImpl.java:41) [junit4] 2> at org.apache.curator.framework.recipes.shared.Sha= redValue.readValue(SharedValue.java:244) [junit4] 2> at org.apache.curator.framework.recipes.shared.Sha= redValue.access$100(SharedValue.java:44) [junit4] 2> at org.apache.curator.framework.recipes.shared.Sha= redValue$1.process(SharedValue.java:61) [junit4] 2> at org.apache.curator.framework.imps.NamespaceWatc= her.process(NamespaceWatcher.java:67) [junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.pro= cessEvent(ClientCnxn.java:530) [junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run= (ClientCnxn.java:505) [junit4] 2> 2) Thread[id=3D3776, name=3Djetty-launcher-872-thread-2= -EventThread, state=3DTIMED_WAITING, group=3DTGRP-TestSolrCloudWithSecureIm= personation] [junit4] 2> at sun.misc.Unsafe.park(Native Method) [junit4] 2> at java.util.concurrent.locks.LockSupport.parkNano= s(LockSupport.java:215) [junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchr= onizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1037) [junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchr= onizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1328) [junit4] 2> at java.util.concurrent.CountDownLatch.await(Count= DownLatch.java:277) [junit4] 2> at org.apache.curator.CuratorZookeeperClient.inter= nalBlockUntilConnectedOrTimedOut(CuratorZookeeperClient.java:323) [junit4] 2> at org.apache.curator.RetryLoop.callWithRetry(Retr= yLoop.java:105) [junit4] 2> at org.apache.curator.framework.imps.GetDataBuilde= rImpl.pathInForeground(GetDataBuilderImpl.java:288) [junit4] 2> at org.apache.curator.framework.imps.GetDataBuilde= rImpl.forPath(GetDataBuilderImpl.java:279) [junit4] 2> at org.apache.curator.framework.imps.GetDataBuilde= rImpl.forPath(GetDataBuilderImpl.java:41) [junit4] 2> at org.apache.curator.framework.recipes.shared.Sha= redValue.readValue(SharedValue.java:244) [junit4] 2> at org.apache.curator.framework.recipes.shared.Sha= redValue.access$100(SharedValue.java:44) [junit4] 2> at org.apache.curator.framework.recipes.shared.Sha= redValue$1.process(SharedValue.java:61) [junit4] 2> at org.apache.curator.framework.imps.NamespaceWatc= her.process(NamespaceWatcher.java:67) [junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.pro= cessEvent(ClientCnxn.java:530) [junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run= (ClientCnxn.java:505) [junit4] 2> Dec 18, 2017 5:12:10 PM com.carrotsearch.randomizedtesting= .ThreadLeakControl tryToInterruptAll [junit4] 2> INFO: Starting to interrupt leaked threads: [junit4] 2> 1) Thread[id=3D3777, name=3Djetty-launcher-872-thread-1= -EventThread, state=3DTIMED_WAITING, group=3DTGRP-TestSolrCloudWithSecureIm= personation] [junit4] 2> 2) Thread[id=3D3776, name=3Djetty-launcher-872-thread-2= -EventThread, state=3DTIMED_WAITING, group=3DTGRP-TestSolrCloudWithSecureIm= personation] [junit4] 2> 329117 ERROR (jetty-launcher-872-thread-2-EventThread) [n:= 127.0.0.1:38887_solr ] o.a.c.f.i.CuratorFrameworkImpl Watcher exception [junit4] 2> java.lang.InterruptedException [junit4] 2> =09at java.util.concurrent.locks.AbstractQueuedSynchronize= r.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1039) [junit4] 2> =09at java.util.concurrent.locks.AbstractQueuedSynchronize= r.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1328) [junit4] 2> =09at java.util.concurrent.CountDownLatch.await(CountDownL= atch.java:277) [junit4] 2> =09at org.apache.curator.CuratorZookeeperClient.internalBl= ockUntilConnectedOrTimedOut(CuratorZookeeperClient.java:323) [junit4] 2> =09at org.apache.curator.RetryLoop.callWithRetry(RetryLoop= .java:105) [junit4] 2> =09at org.apache.curator.framework.imps.GetDataBuilderImpl= .pathInForeground(GetDataBuilderImpl.java:288) [junit4] 2> =09at org.apache.curator.framework.imps.GetDataBuilderImpl= .forPath(GetDataBuilderImpl.java:279) [junit4] 2> =09at org.apache.curator.framework.imps.GetDataBuilderImpl= .forPath(GetDataBuilderImpl.java:41) [junit4] 2> =09at org.apache.curator.framework.recipes.shared.SharedVa= lue.readValue(SharedValue.java:244) [junit4] 2> =09at org.apache.curator.framework.recipes.shared.SharedVa= lue.access$100(SharedValue.java:44) [junit4] 2> =09at org.apache.curator.framework.recipes.shared.SharedVa= lue$1.process(SharedValue.java:61) [junit4] 2> =09at org.apache.curator.framework.imps.NamespaceWatcher.p= rocess(NamespaceWatcher.java:67) [junit4] 2> =09at org.apache.zookeeper.ClientCnxn$EventThread.processE= vent(ClientCnxn.java:530) [junit4] 2> =09at org.apache.zookeeper.ClientCnxn$EventThread.run(Clie= ntCnxn.java:505) [junit4] 2> 329117 ERROR (jetty-launcher-872-thread-1-EventThread) [n:= 127.0.0.1:39099_solr ] o.a.c.f.i.CuratorFrameworkImpl Watcher exception [junit4] 2> java.lang.InterruptedException [junit4] 2> =09at java.util.concurrent.locks.AbstractQueuedSynchronize= r.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1039) [junit4] 2> =09at java.util.concurrent.locks.AbstractQueuedSynchronize= r.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1328) [junit4] 2> =09at java.util.concurrent.CountDownLatch.await(CountDownL= atch.java:277) [junit4] 2> =09at org.apache.curator.CuratorZookeeperClient.internalBl= ockUntilConnectedOrTimedOut(CuratorZookeeperClient.java:323) [junit4] 2> =09at org.apache.curator.RetryLoop.callWithRetry(RetryLoop= .java:105) [junit4] 2> =09at org.apache.curator.framework.imps.GetDataBuilderImpl= .pathInForeground(GetDataBuilderImpl.java:288) [junit4] 2> =09at org.apache.curator.framework.imps.GetDataBuilderImpl= .forPath(GetDataBuilderImpl.java:279) [junit4] 2> =09at org.apache.curator.framework.imps.GetDataBuilderImpl= .forPath(GetDataBuilderImpl.java:41) [junit4] 2> =09at org.apache.curator.framework.recipes.shared.SharedVa= lue.readValue(SharedValue.java:244) [junit4] 2> =09at org.apache.curator.framework.recipes.shared.SharedVa= lue.access$100(SharedValue.java:44) [junit4] 2> =09at org.apache.curator.framework.recipes.shared.SharedVa= lue$1.process(SharedValue.java:61) [junit4] 2> =09at org.apache.curator.framework.imps.NamespaceWatcher.p= rocess(NamespaceWatcher.java:67) [junit4] 2> =09at org.apache.zookeeper.ClientCnxn$EventThread.processE= vent(ClientCnxn.java:530) [junit4] 2> =09at org.apache.zookeeper.ClientCnxn$EventThread.run(Clie= ntCnxn.java:505) [junit4] 2> 329119 WARN (jetty-launcher-872-thread-1-EventThread) [n:= 127.0.0.1:39099_solr ] o.a.c.ConnectionState Session expired event recei= ved [junit4] 2> 329119 WARN (jetty-launcher-872-thread-2-EventThread) [n:= 127.0.0.1:38887_solr ] o.a.c.ConnectionState Session expired event recei= ved [junit4] 2> 329120 WARN (jetty-launcher-872-thread-1-SendThread(127.0= .0.1:33473)) [n:127.0.0.1:39099_solr ] o.a.z.ClientCnxn Session 0x0 for = server null, unexpected error, closing socket connection and attempting rec= onnect [junit4] 2> java.net.ConnectException: Connection refused [junit4] 2> =09at sun.nio.ch.SocketChannelImpl.checkConnect(Native Met= hod) [junit4] 2> =09at sun.nio.ch.SocketChannelImpl.finishConnect(SocketCha= nnelImpl.java:717) [junit4] 2> =09at org.ap [...truncated too long message...] o.ch.SocketChannelImpl.checkConnect(Native Method) [junit4] 2> =09at sun.nio.ch.SocketChannelImpl.finishConnect(SocketCha= nnelImpl.java:717) [junit4] 2> =09at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport= (ClientCnxnSocketNIO.java:361) [junit4] 2> =09at org.apache.zookeeper.ClientCnxn$SendThread.run(Clien= tCnxn.java:1141) [junit4] IGNOR/A 0.00s J2 | TestFieldCacheVsDocValues.testHugeBinaryValu= eLimit [junit4] > Assumption #1: test requires codec with limits on max bina= ry field length [junit4] 2> 2476385 WARN (jetty-launcher-872-thread-1-SendThread(127.= 0.0.1:33473)) [n:127.0.0.1:39099_solr ] o.a.z.ClientCnxn Session 0x0 for= server null, unexpected error, closing socket connection and attempting re= connect [junit4] 2> java.net.ConnectException: Connection refused [junit4] 2> =09at sun.nio.ch.SocketChannelImpl.checkConnect(Native Met= hod) [junit4] 2> =09at sun.nio.ch.SocketChannelImpl.finishConnect(SocketCha= nnelImpl.java:717) [junit4] 2> =09at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport= (ClientCnxnSocketNIO.java:361) [junit4] 2> =09at org.apache.zookeeper.ClientCnxn$SendThread.run(Clien= tCnxn.java:1141) [junit4] 2> 2476385 WARN (jetty-launcher-872-thread-2-SendThread(127.= 0.0.1:33473)) [n:127.0.0.1:38887_solr ] o.a.z.ClientCnxn Session 0x0 for= server null, unexpected error, closing socket connection and attempting re= connect [junit4] 2> java.net.ConnectException: Connection refused [junit4] 2> =09at sun.nio.ch.SocketChannelImpl.checkConnect(Native Met= hod) [junit4] 2> =09at sun.nio.ch.SocketChannelImpl.finishConnect(SocketCha= nnelImpl.java:717) [junit4] 2> =09at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport= (ClientCnxnSocketNIO.java:361) [junit4] 2> =09at org.apache.zookeeper.ClientCnxn$SendThread.run(Clien= tCnxn.java:1141) [junit4] 2> NOTE: test params are: codec=3DAsserting(Lucene70), sim=3D= RandomSimilarity(queryNorm=3Dfalse): {}, locale=3Des-CO, timezone=3DAfrica/= Sao_Tome [junit4] 2> NOTE: Linux 4.10.0-40-generic i386/Oracle Corporation 1.8.= 0_144 (32-bit)/cpus=3D8,threads=3D1,free=3D121626856,total=3D531890176 [junit4] 2> NOTE: All tests run in this JVM: [HdfsChaosMonkeyNothingIs= SafeTest, OverseerTest, TimeRoutedAliasUpdateProcessorTest, TestCloudPivotF= acet, TestSystemCollAutoCreate, TestPartialUpdateDeduplication, Distributed= FacetPivotLongTailTest, SolrGraphiteReporterTest, TestCloudSchemaless, Test= ConfigsApi, DistributedSuggestComponentTest, AddBlockUpdateTest, TestFieldC= acheReopen, DistanceFunctionTest, TestCSVResponseWriter, UUIDFieldTest, Tes= tHdfsCloudBackupRestore, LoggingHandlerTest, TestSha256AuthenticationProvid= er, TestQuerySenderListener, TestPolicyCloud, BasicDistributedZk2Test, Coll= ectionReloadTest, SpatialRPTFieldTypeTest, ReturnFieldsTest, TestReload, Te= stSolrCloudWithSecureImpersonation, TestExactSharedStatsCache, VersionInfoT= est, TestNumericTokenStream, TestXmlQParser, TestFiltering, CdcrReplication= DistributedZkTest, TestDocBasedVersionConstraints, TestRetrieveFieldsOptimi= zer, ComputePlanActionTest, MergeStrategyTest, DirectSolrSpellCheckerTest, = ResponseHeaderTest, CachingDirectoryFactoryTest, SuggesterWFSTTest, TestSol= r4Spatial2, BadComponentTest, TestDynamicFieldResource, TestIndexSearcher, = TestOverriddenPrefixQueryForCustomFieldType, CoreAdminHandlerTest, Collecti= onsAPIAsyncDistributedZkTest, TestMissingGroups, TestSQLHandlerNonCloud, Te= stConfigSetsAPIZkFailure, ReplicaListTransformerTest, TestImplicitCorePrope= rties, TestMiniSolrCloudClusterSSL, UnloadDistributedZkTest, TestNumericTer= ms32, ClusterStateTest, ConnectionReuseTest, TestStandardQParsers, HdfsRest= artWhileUpdatingTest, TestLeaderInitiatedRecoveryThread, DataDrivenBlockJoi= nTest, WordBreakSolrSpellCheckerTest, TestDistributedMissingSort, SimplePos= tToolTest, TestSchemaResource, TestTolerantUpdateProcessorRandomCloud, Test= UnifiedSolrHighlighter, TestGroupingSearch, TestLMJelinekMercerSimilarityFa= ctory, TestManagedResource, TestZkChroot, TestCharFilters, ClassificationUp= dateProcessorTest, TestManagedSchema, TriLevelCompositeIdRoutingTest, Migra= teRouteKeyTest, GraphQueryTest, SpellPossibilityIteratorTest, TestRandomReq= uestDistribution, DirectoryFactoryTest, ScriptEngineTest, AsyncCallRequestS= tatusResponseTest, AnalyticsQueryTest, LeaderElectionContextKeyTest, MoveRe= plicaHDFSTest, ExplicitHLLTest, DeleteStatusTest, TestPushWriter, TestTrie,= OverseerStatusTest, TestDistributedGrouping, TestLMDirichletSimilarityFact= ory, SuggestComponentContextFilterQueryTest, TestAnalyzeInfixSuggestions, T= estDistribStateManager, TestSolrCoreProperties, TestElisionMultitermQuery, = BlockDirectoryTest, TestExtendedDismaxParser, DefaultValueUpdateProcessorTe= st, TestSkipOverseerOperations, TestComplexPhraseQParserPlugin, TestTestInj= ection, AutoAddReplicasIntegrationTest, TestSerializedLuceneMatchVersion, D= istanceUnitsTest, UniqFieldsUpdateProcessorFactoryTest, ZkStateWriterTest, = BaseCdcrDistributedZkTest, TestExpandComponent, TestJsonFacetRefinement, Au= toscalingHistoryHandlerTest, TestStressLiveNodes, TestFuzzyAnalyzedSuggesti= ons, HLLUtilTest, TimeZoneUtilsTest, TestScoreJoinQPNoScore, EchoParamsTest= , DistributedExpandComponentTest, TestGeoJSONResponseWriter, HdfsLockFactor= yTest, TestPointFields, RecoveryAfterSoftCommitTest, BasicAuthIntegrationTe= st, FullSolrCloudDistribCmdsTest, ClusterStateUpdateTest, LeaderElectionTes= t, TestRandomDVFaceting, ShardRoutingCustomTest, TestFaceting, DistributedS= pellCheckComponentTest, TermVectorComponentDistributedTest, TestJoin, TestC= oreContainer, SimpleFacetsTest, SolrCoreTest, SolrCmdDistributorTest, Query= ElevationComponentTest, BadIndexSchemaTest, ConvertedLegacyTest, TestLazyCo= res, TestCoreDiscovery, DocValuesTest, SortByFunctionTest, TestSolrDeletion= Policy1, DebugComponentTest, IndexBasedSpellCheckerTest, DisMaxRequestHandl= erTest, TestWriterPerf, TestQueryTypes, FileBasedSpellCheckerTest, XmlUpdat= eRequestHandlerTest, DocumentBuilderTest, TermVectorComponentTest, Required= FieldsTest, TestSolrQueryParser, FastVectorHighlighterTest, TestJmxIntegrat= ion, JsonLoaderTest, TestPHPSerializedResponseWriter, CSVRequestHandlerTest= , TestComponentsName, SearchHandlerTest, AlternateDirectoryTest, TestQueryS= enderNoQuery, CopyFieldTest, ResponseLogComponentTest, SolrIndexConfigTest,= TestStressRecovery, TestSolrDeletionPolicy2, SampleTest, TestBinaryField, = TestSearchPerf, NumericFieldsTest, MinimalSchemaTest, TestConfig, ExternalF= ileFieldSortTest, DirectSolrConnectionTest, NotRequiredUniqueKeyTest, TestL= uceneMatchVersion, TestPhraseSuggestions, TestCodecSupport, SynonymTokenize= rTest, TestIBSimilarityFactory, OpenExchangeRatesOrgProviderTest, PluginInf= oTest, DateMathParserTest, ChaosMonkeyNothingIsSafeTest, AssignTest, Cleanu= pOldIndexTest, CloudExitableDirectoryReaderTest, CollectionStateFormat2Test= , CollectionsAPISolrJTest, DeleteShardTest, DistributedQueueTest, LeaderFai= loverAfterPartitionTest, LeaderInitiatedRecoveryOnCommitTest, MissingSegmen= tRecoveryTest, MoveReplicaTest, NodeMutatorTest, OverriddenZkACLAndCredenti= alsProvidersTest, ReplaceNodeTest, ReplicationFactorTest, SSLMigrationTest,= SharedFSAutoReplicaFailoverTest, SimpleCollectionCreateDeleteTest, TestClo= udDeleteByQuery, TestCloudJSONFacetJoinDomain, TestConfigSetsAPI, TestPullR= eplicaErrorHandling, TestSegmentSorting, VMParamsZkACLAndCredentialsProvide= rsTest, HdfsAutoAddReplicasIntegrationTest, HdfsBasicDistributedZk2Test, Hd= fsChaosMonkeySafeLeaderTest, HdfsNNFailoverTest, HdfsSyncSliceTest, HdfsThr= eadLeakTest, TestClusterStateMutator, ImplicitSnitchTest, RuleEngineTest, R= ulesTest, QueryResultKeyTest, TestConfigSetImmutable, TestCorePropertiesRel= oad, TestDynamicLoading, TestReplicationHandlerBackup, V2StandaloneTest, Co= reAdminCreateDiscoverTest, CoreAdminRequestStatusTest, CoreMergeIndexesAdmi= nHandlerTest, InfoHandlerTest, PropertiesRequestHandlerTest, SecurityConfHa= ndlerTest, StatsReloadRaceTest, TestSlowCompositeReaderWrapper, UninvertDoc= ValuesMergePolicyTest, WrapperMergePolicyFactoryTest, CheckHdfsIndexTest, T= estMacroExpander, TestMacros, JSONWriterTest, TestBinaryResponseWriter, Tes= tExportWriter, TestRawResponseWriter, TestSolrQueryResponse, TestChildDocTr= ansformer, TestSubQueryTransformer, TestSubQueryTransformerCrossCore, TestS= ubQueryTransformerDistrib, TestDynamicFieldCollectionResource, TestFieldTyp= eCollectionResource, TestFieldTypeResource, TestUniqueKeyFieldResource, Tes= tManagedStopFilterFactory, TestManagedSynonymGraphFilterFactory, DateRangeF= ieldTest, DocValuesMissingTest, TestBulkSchemaConcurrent, SortSpecParsingTe= st, TestAddFieldRealTimeGet, TestCollapseQParserPlugin, TestComplexPhraseLe= adingWildcard, TestFilteredDocIdSet, TestInitQParser, TestQueryWrapperFilte= r, TestReRankQParserPlugin, TestReloadDeadlock, TestSearcherReuse, TestSimp= leQParserPlugin, TestSolrCoreParser, TestXmlQParserPlugin, DistributedFacet= SimpleRefinementLongTailTest, TestJsonFacets, TestMinMaxOnMultiValuedField,= TestOrdValues, BlockJoinFacetDistribTest, TestDFISimilarityFactory, TestNo= nDefinedSimilarityFactory, TestLRUStatsCache, TestAuthorizationFramework, T= estImpersonationWithHadoopAuth, TestDocTermOrds, TestFieldCache, TestFieldC= acheSort, TestFieldCacheVsDocValues] [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=3DTestFieldCach= eVsDocValues -Dtests.seed=3D70A943F10BDA666F -Dtests.multiplier=3D3 -Dtests= .slow=3Dtrue -Dtests.locale=3Des-CO -Dtests.timezone=3DAfrica/Sao_Tome -Dte= sts.asserts=3Dtrue -Dtests.file.encoding=3DISO-8859-1 [junit4] ERROR 0.00s J2 | TestFieldCacheVsDocValues (suite) <<< [junit4] > Throwable #1: java.lang.AssertionError: The test or suite = printed 13392 bytes to stdout and stderr, even though the limit was set to = 8192 bytes. Increase the limit with @Limit, ignore it completely with @Supp= ressSysoutChecks or run with -Dtests.verbose=3Dtrue [junit4] > =09at __randomizedtesting.SeedInfo.seed([70A943F10BDA666F]= :0) [junit4] > =09at java.lang.Thread.run(Thread.java:748) [junit4] Completed [743/763 (3!)] on J2 in 7.53s, 10 tests, 1 failure, 1= skipped <<< FAILURES! [...truncated 43948 lines...] ------=_Part_188_651998426.1513620060501 Content-Type: text/plain; charset=us-ascii --------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org For additional commands, e-mail: dev-help@lucene.apache.org ------=_Part_188_651998426.1513620060501--