Return-Path: X-Original-To: apmail-hbase-issues-archive@www.apache.org Delivered-To: apmail-hbase-issues-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id A3A4317748 for ; Wed, 23 Sep 2015 19:13:11 +0000 (UTC) Received: (qmail 43435 invoked by uid 500); 23 Sep 2015 19:13:05 -0000 Delivered-To: apmail-hbase-issues-archive@hbase.apache.org Received: (qmail 43383 invoked by uid 500); 23 Sep 2015 19:13:05 -0000 Mailing-List: contact issues-help@hbase.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Delivered-To: mailing list issues@hbase.apache.org Received: (qmail 43163 invoked by uid 99); 23 Sep 2015 19:13:05 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 23 Sep 2015 19:13:05 +0000 Date: Wed, 23 Sep 2015 19:13:05 +0000 (UTC) From: "stack (JIRA)" To: issues@hbase.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (HBASE-14430) TestHttpServerLifecycle#testStartedServerIsAlive times out MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/HBASE-14430?page=3Dcom.atlassia= n.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=3D149= 05060#comment-14905060 ]=20 stack commented on HBASE-14430: ------------------------------- I need to turn off even more.... Tests in error: TestHttpServerLifecycle.testStoppingTwiceServerIsAllowed:110->HttpServerF= unctionalTest.stop:195 =C2=BB TestTimedOut > TestHttpServerLifecycle#testStartedServerIsAlive times out > ---------------------------------------------------------- > > Key: HBASE-14430 > URL: https://issues.apache.org/jira/browse/HBASE-14430 > Project: HBase > Issue Type: Sub-task > Components: test > Reporter: stack > > Running on my test rig, I see this test timeout from time to time. It jus= t hangs after jetty setup. Port clash? > {code} > 2015-09-14 09:08:54,474 INFO [main] hbase.ResourceChecker(148): before: = http.TestHttpServerLifecycle#testCreatedServerIsNotAlive Thread=3D4, OpenFi= leDescriptor=3D192, MaxFileDescriptor=3D32768, SystemLoadAverage=3D122, Pro= cessCount=3D507, Availabl > 2015-09-14 09:08:54,592 INFO [Time-limited test] log.Slf4jLog(67): Loggi= ng to org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via org.mortbay.lo= g.Slf4jLog > 2015-09-14 09:08:54,911 INFO [Time-limited test] http.HttpRequestLog(69)= : Http request log for http.requests.test is not defined > 2015-09-14 09:08:54,923 INFO [Time-limited test] http.HttpServer(821): A= dded global filter 'safety' (class=3Dorg.apache.hadoop.hbase.http.HttpServe= r$QuotingInputFilter) > 2015-09-14 09:08:54,924 INFO [Time-limited test] http.HttpServer(821): A= dded global filter 'clickjackingprevention' (class=3Dorg.apache.hadoop.hbas= e.http.ClickjackingPreventionFilter) > 2015-09-14 09:08:54,985 INFO [main] hbase.ResourceChecker(172): after: h= ttp.TestHttpServerLifecycle#testCreatedServerIsNotAlive Thread=3D5 (was 4) > Potentially hanging thread: process reaper > sun.misc.Unsafe.park(Native Method) > java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java= :226) > java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(= SynchronousQueue.java:460) > java.util.concurrent.SynchronousQueue$TransferStack.transfer(Sync= hronousQueue.java:359) > java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:= 942) > java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecuto= r.java:1068) > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecu= tor.java:1130) > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExec= utor.java:615) > java.lang.Thread.run(Thread.java:745) > - Thread LEAK? -, OpenFileDescriptor=3D192 (was 192), MaxFileDescriptor= =3D32768 (was 32768), SystemLoadAverage=3D122 (was 122), ProcessCount=3D507= (was 507), AvailableMemoryMB=3D28014 (was 28054) > 2015-09-14 09:08:55,013 INFO [main] hbase.ResourceChecker(148): before: = http.TestHttpServerLifecycle#testWepAppContextAfterServerStop Thread=3D5, O= penFileDescriptor=3D192, MaxFileDescriptor=3D32768, SystemLoadAverage=3D122= , ProcessCount=3D507, Ava > 2015-09-14 09:08:55,088 INFO [Time-limited test] http.HttpRequestLog(69)= : Http request log for http.requests.test is not defined > 2015-09-14 09:08:55,089 INFO [Time-limited test] http.HttpServer(821): A= dded global filter 'safety' (class=3Dorg.apache.hadoop.hbase.http.HttpServe= r$QuotingInputFilter) > 2015-09-14 09:08:55,090 INFO [Time-limited test] http.HttpServer(821): A= dded global filter 'clickjackingprevention' (class=3Dorg.apache.hadoop.hbas= e.http.ClickjackingPreventionFilter) > 2015-09-14 09:08:55,113 INFO [Time-limited test] http.HttpServer(1013): = Jetty bound to port 60242 > 2015-09-14 09:08:55,113 INFO [Time-limited test] log.Slf4jLog(67): jetty= -6.1.26 > 2015-09-14 09:08:55,263 INFO [Time-limited test] log.Slf4jLog(67): Start= ed SelectChannelConnector@localhost:60242 > 2015-09-14 09:08:55,270 INFO [Time-limited test] log.Slf4jLog(67): Stopp= ed SelectChannelConnector@localhost:0 > 2015-09-14 09:08:55,401 INFO [main] hbase.ResourceChecker(172): after: h= ttp.TestHttpServerLifecycle#testWepAppContextAfterServerStop Thread=3D5 (wa= s 5), OpenFileDescriptor=3D197 (was 192) - OpenFileDescriptor LEAK? -, MaxF= ileDescriptor=3D32768 > 2015-09-14 09:08:55,428 INFO [main] hbase.ResourceChecker(148): before: = http.TestHttpServerLifecycle#testStopUnstartedServer Thread=3D5, OpenFileDe= scriptor=3D197, MaxFileDescriptor=3D32768, SystemLoadAverage=3D122, Process= Count=3D507, AvailableMem > 2015-09-14 09:08:55,489 INFO [Time-limited test] http.HttpRequestLog(69)= : Http request log for http.requests.test is not defined > 2015-09-14 09:08:55,489 INFO [Time-limited test] http.HttpServer(821): A= dded global filter 'safety' (class=3Dorg.apache.hadoop.hbase.http.HttpServe= r$QuotingInputFilter) > 2015-09-14 09:08:55,490 INFO [Time-limited test] http.HttpServer(821): A= dded global filter 'clickjackingprevention' (class=3Dorg.apache.hadoop.hbas= e.http.ClickjackingPreventionFilter) > 2015-09-14 09:08:55,521 INFO [main] hbase.ResourceChecker(172): after: h= ttp.TestHttpServerLifecycle#testStopUnstartedServer Thread=3D5 (was 5), Ope= nFileDescriptor=3D197 (was 197), MaxFileDescriptor=3D32768 (was 32768), Sys= temLoadAverage=3D122 (w > 2015-09-14 09:08:55,548 INFO [main] hbase.ResourceChecker(148): before: = http.TestHttpServerLifecycle#testStartedServerIsAlive Thread=3D5, OpenFileD= escriptor=3D197, MaxFileDescriptor=3D32768, SystemLoadAverage=3D122, Proces= sCount=3D507, AvailableMe > 2015-09-14 09:08:55,592 INFO [Time-limited test] http.HttpRequestLog(69)= : Http request log for http.requests.test is not defined > 2015-09-14 09:08:55,593 INFO [Time-limited test] http.HttpServer(821): A= dded global filter 'safety' (class=3Dorg.apache.hadoop.hbase.http.HttpServe= r$QuotingInputFilter) > 2015-09-14 09:08:55,593 INFO [Time-limited test] http.HttpServer(821): A= dded global filter 'clickjackingprevention' (class=3Dorg.apache.hadoop.hbas= e.http.ClickjackingPreventionFilter) > 2015-09-14 09:08:55,596 INFO [Time-limited test] http.HttpServer(1013): = Jetty bound to port 34027 > 2015-09-14 09:08:55,596 INFO [Time-limited test] log.Slf4jLog(67): jetty= -6.1.26 > 2015-09-14 09:08:55,620 INFO [Time-limited test] log.Slf4jLog(67): Start= ed SelectChannelConnector@localhost:34027 > 2015-09-14 09:09:55,589 INFO [main] hbase.ResourceChecker(172): after: h= ttp.TestHttpServerLifecycle#testStartedServerIsAlive Thread=3D8 (was 5) > Potentially hanging thread: 665017523@qtp-1303167268-1 - Acceptor0 Select= ChannelConnector@localhost:34027 > org.mortbay.io.nio.SelectorManager$SelectSet.doSelect(SelectorMan= ager.java:464) > org.mortbay.io.nio.SelectorManager.doSelect(SelectorManager.java:= 192) > org.mortbay.jetty.nio.SelectChannelConnector.accept(SelectChannel= Connector.java:124) > org.mortbay.jetty.AbstractConnector$Acceptor.run(AbstractConnecto= r.java:708) > org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPo= ol.java:582) > Potentially hanging thread: Time-limited test > org.mortbay.io.nio.SelectorManager$SelectSet.stop(SelectorManager= .java:879) > org.mortbay.io.nio.SelectorManager.doStop(SelectorManager.java:24= 0) > org.mortbay.component.AbstractLifeCycle.stop(AbstractLifeCycle.ja= va:76) > org.mortbay.jetty.nio.SelectChannelConnector.close(SelectChannelC= onnector.java:136) > org.apache.hadoop.hbase.http.HttpServer.stop(HttpServer.java:1041= ) > org.apache.hadoop.hbase.http.HttpServerFunctionalTest.stop(HttpSe= rverFunctionalTest.java:195) > org.apache.hadoop.hbase.http.TestHttpServerLifecycle.testStartedS= erverIsAlive(TestHttpServerLifecycle.java:73) > sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorI= mpl.java:57) > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodA= ccessorImpl.java:43) > java.lang.reflect.Method.invoke(Method.java:606) > org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(Frame= workMethod.java:50) > org.junit.internal.runners.model.ReflectiveCallable.run(Reflectiv= eCallable.java:12) > org.junit.runners.model.FrameworkMethod.invokeExplosively(Framewo= rkMethod.java:47) > org.junit.internal.runners.statements.InvokeMethod.evaluate(Invok= eMethod.java:17) > org.junit.internal.runners.statements.FailOnTimeout$CallableState= ment.call(FailOnTimeout.java:298) > org.junit.internal.runners.statements.FailOnTimeout$CallableState= ment.call(FailOnTimeout.java:292) > java.util.concurrent.FutureTask.run(FutureTask.java:262) > java.lang.Thread.run(Thread.java:745) > Potentially hanging thread: Timer-1 > java.lang.Object.wait(Native Method) > java.util.TimerThread.mainLoop(Timer.java:552) > java.util.TimerThread.run(Timer.java:505) > Potentially hanging thread: 1272155315@qtp-1303167268-0 > java.lang.Object.wait(Native Method) > org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPo= ol.java:626) > - Thread LEAK? -, OpenFileDescriptor=3D201 (was 197) - OpenFileDescripto= r LEAK? -, MaxFileDescriptor=3D32768 (was 32768), SystemLoadAverage=3D112 (= was 122), ProcessCount=3D507 (was 507), AvailableMemoryMB=3D27985 (was 2799= 4) > 2015-09-14 09:09:55,619 INFO [main] hbase.ResourceChecker(148): before: = http.TestHttpServerLifecycle#testStoppedServerIsNotAlive Thread=3D9, OpenFi= leDescriptor=3D201, MaxFileDescriptor=3D32768, SystemLoadAverage=3D112, Pro= cessCount=3D507, Availabl > 2015-09-14 09:09:55,652 INFO [Time-limited test] http.HttpRequestLog(69)= : Http request log for http.requests.test is not defined > 2015-09-14 09:09:55,653 INFO [Time-limited test] http.HttpServer(821): A= dded global filter 'safety' (class=3Dorg.apache.hadoop.hbase.http.HttpServe= r$QuotingInputFilter) > 2015-09-14 09:09:55,654 INFO [Time-limited test] http.HttpServer(821): A= dded global filter 'clickjackingprevention' (class=3Dorg.apache.hadoop.hbas= e.http.ClickjackingPreventionFilter) > 2015-09-14 09:09:55,657 INFO [Time-limited test] http.HttpServer(1013): = Jetty bound to port 49253 > 2015-09-14 09:09:55,657 INFO [Time-limited test] log.Slf4jLog(67): jetty= -6.1.26 > 2015-09-14 09:09:55,681 INFO [Time-limited test] log.Slf4jLog(67): Start= ed SelectChannelConnector@localhost:49253 > 2015-09-14 09:09:55,684 INFO [Time-limited test] log.Slf4jLog(67): Stopp= ed SelectChannelConnector@localhost:0 > 2015-09-14 09:09:55,817 INFO [main] hbase.ResourceChecker(172): after: h= ttp.TestHttpServerLifecycle#testStoppedServerIsNotAlive Thread=3D9 (was 9),= OpenFileDescriptor=3D201 (was 201), MaxFileDescriptor=3D32768 (was 32768),= SystemLoadAverage=3D11 > 2015-09-14 09:09:55,847 INFO [main] hbase.ResourceChecker(148): before: = http.TestHttpServerLifecycle#testStoppingTwiceServerIsAllowed Thread=3D9, O= penFileDescriptor=3D201, MaxFileDescriptor=3D32768, SystemLoadAverage=3D112= , ProcessCount=3D507, Ava > 2015-09-14 09:09:55,879 INFO [Time-limited test] http.HttpRequestLog(69)= : Http request log for http.requests.test is not defined > 2015-09-14 09:09:55,880 INFO [Time-limited test] http.HttpServer(821): A= dded global filter 'safety' (class=3Dorg.apache.hadoop.hbase.http.HttpServe= r$QuotingInputFilter) > 2015-09-14 09:09:55,880 INFO [Time-limited test] http.HttpServer(821): A= dded global filter 'clickjackingprevention' (class=3Dorg.apache.hadoop.hbas= e.http.ClickjackingPreventionFilter) > 2015-09-14 09:09:55,883 INFO [Time-limited test] http.HttpServer(1013): = Jetty bound to port 53449 > 2015-09-14 09:09:55,884 INFO [Time-limited test] log.Slf4jLog(67): jetty= -6.1.26 > 2015-09-14 09:09:55,906 INFO [Time-limited test] log.Slf4jLog(67): Start= ed SelectChannelConnector@localhost:53449 > 2015-09-14 09:09:55,910 INFO [Time-limited test] log.Slf4jLog(67): Stopp= ed SelectChannelConnector@localhost:0 > 2015-09-14 09:09:56,038 INFO [main] hbase.ResourceChecker(172): after: h= ttp.TestHttpServerLifecycle#testStoppingTwiceServerIsAllowed Thread=3D9 (wa= s 9), OpenFileDescriptor=3D201 (was 201), MaxFileDescriptor=3D32768 (was 32= 768), SystemLoadAvera > {code} > This test came over from hadoop.=20 > Looking at history, it usually passes up on apache jenkins so not disabli= ng for now. Just noting this failure. > https://builds.apache.org/view/H-L/view/HBase/job/PreCommit-HBASE-Build/1= 5579/testReport/org.apache.hadoop.hbase.http/TestHttpServerLifecycle/histor= y/ -- This message was sent by Atlassian JIRA (v6.3.4#6332)