hbase-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "stack (JIRA)" <j...@apache.org>
Subject [jira] [Created] (HBASE-14430) TestHttpServerLifecycle#testStartedServerIsAlive times out
Date Mon, 14 Sep 2015 16:57:46 GMT
stack created HBASE-14430:
-----------------------------

             Summary: TestHttpServerLifecycle#testStartedServerIsAlive times out
                 Key: HBASE-14430
                 URL: https://issues.apache.org/jira/browse/HBASE-14430
             Project: HBase
          Issue Type: Sub-task
            Reporter: stack


Running on my test rig, I see this test timeout from time to time. It just hangs after jetty
setup. Port clash?

{code}
2015-09-14 09:08:54,474 INFO  [main] hbase.ResourceChecker(148): before: http.TestHttpServerLifecycle#testCreatedServerIsNotAlive
Thread=4, OpenFileDescriptor=192, MaxFileDescriptor=32768, SystemLoadAverage=122, ProcessCount=507,
Availabl
2015-09-14 09:08:54,592 INFO  [Time-limited test] log.Slf4jLog(67): Logging to org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log)
via org.mortbay.log.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): Added global filter
'safety' (class=org.apache.hadoop.hbase.http.HttpServer$QuotingInputFilter)
2015-09-14 09:08:54,924 INFO  [Time-limited test] http.HttpServer(821): Added global filter
'clickjackingprevention' (class=org.apache.hadoop.hbase.http.ClickjackingPreventionFilter)
2015-09-14 09:08:54,985 INFO  [main] hbase.ResourceChecker(172): after: http.TestHttpServerLifecycle#testCreatedServerIsNotAlive
Thread=5 (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(SynchronousQueue.java:359)
        java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:942)
        java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
        java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
        java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        java.lang.Thread.run(Thread.java:745)
 - Thread LEAK? -, OpenFileDescriptor=192 (was 192), MaxFileDescriptor=32768 (was 32768),
SystemLoadAverage=122 (was 122), ProcessCount=507 (was 507), AvailableMemoryMB=28014 (was
28054)
2015-09-14 09:08:55,013 INFO  [main] hbase.ResourceChecker(148): before: http.TestHttpServerLifecycle#testWepAppContextAfterServerStop
Thread=5, OpenFileDescriptor=192, MaxFileDescriptor=32768, SystemLoadAverage=122, ProcessCount=507,
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): Added global filter
'safety' (class=org.apache.hadoop.hbase.http.HttpServer$QuotingInputFilter)
2015-09-14 09:08:55,090 INFO  [Time-limited test] http.HttpServer(821): Added global filter
'clickjackingprevention' (class=org.apache.hadoop.hbase.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): Started SelectChannelConnector@localhost:60242
2015-09-14 09:08:55,270 INFO  [Time-limited test] log.Slf4jLog(67): Stopped SelectChannelConnector@localhost:0
2015-09-14 09:08:55,401 INFO  [main] hbase.ResourceChecker(172): after: http.TestHttpServerLifecycle#testWepAppContextAfterServerStop
Thread=5 (was 5), OpenFileDescriptor=197 (was 192) - OpenFileDescriptor LEAK? -, MaxFileDescriptor=32768
2015-09-14 09:08:55,428 INFO  [main] hbase.ResourceChecker(148): before: http.TestHttpServerLifecycle#testStopUnstartedServer
Thread=5, OpenFileDescriptor=197, MaxFileDescriptor=32768, SystemLoadAverage=122, ProcessCount=507,
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): Added global filter
'safety' (class=org.apache.hadoop.hbase.http.HttpServer$QuotingInputFilter)
2015-09-14 09:08:55,490 INFO  [Time-limited test] http.HttpServer(821): Added global filter
'clickjackingprevention' (class=org.apache.hadoop.hbase.http.ClickjackingPreventionFilter)
2015-09-14 09:08:55,521 INFO  [main] hbase.ResourceChecker(172): after: http.TestHttpServerLifecycle#testStopUnstartedServer
Thread=5 (was 5), OpenFileDescriptor=197 (was 197), MaxFileDescriptor=32768 (was 32768), SystemLoadAverage=122
(w
2015-09-14 09:08:55,548 INFO  [main] hbase.ResourceChecker(148): before: http.TestHttpServerLifecycle#testStartedServerIsAlive
Thread=5, OpenFileDescriptor=197, MaxFileDescriptor=32768, SystemLoadAverage=122, ProcessCount=507,
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): Added global filter
'safety' (class=org.apache.hadoop.hbase.http.HttpServer$QuotingInputFilter)
2015-09-14 09:08:55,593 INFO  [Time-limited test] http.HttpServer(821): Added global filter
'clickjackingprevention' (class=org.apache.hadoop.hbase.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): Started SelectChannelConnector@localhost:34027
2015-09-14 09:09:55,589 INFO  [main] hbase.ResourceChecker(172): after: http.TestHttpServerLifecycle#testStartedServerIsAlive
Thread=8 (was 5)
Potentially hanging thread: 665017523@qtp-1303167268-1 - Acceptor0 SelectChannelConnector@localhost:34027
        org.mortbay.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:464)
        org.mortbay.io.nio.SelectorManager.doSelect(SelectorManager.java:192)
        org.mortbay.jetty.nio.SelectChannelConnector.accept(SelectChannelConnector.java:124)
        org.mortbay.jetty.AbstractConnector$Acceptor.run(AbstractConnector.java:708)
        org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.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:240)
        org.mortbay.component.AbstractLifeCycle.stop(AbstractLifeCycle.java:76)
        org.mortbay.jetty.nio.SelectChannelConnector.close(SelectChannelConnector.java:136)
        org.apache.hadoop.hbase.http.HttpServer.stop(HttpServer.java:1041)
        org.apache.hadoop.hbase.http.HttpServerFunctionalTest.stop(HttpServerFunctionalTest.java:195)
        org.apache.hadoop.hbase.http.TestHttpServerLifecycle.testStartedServerIsAlive(TestHttpServerLifecycle.java:73)
        sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        java.lang.reflect.Method.invoke(Method.java:606)
        org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
        org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
        org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
        org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
        org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298)
        org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.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(QueuedThreadPool.java:626)
 - Thread LEAK? -, OpenFileDescriptor=201 (was 197) - OpenFileDescriptor LEAK? -, MaxFileDescriptor=32768
(was 32768), SystemLoadAverage=112 (was 122), ProcessCount=507 (was 507), AvailableMemoryMB=27985
(was 27994)
2015-09-14 09:09:55,619 INFO  [main] hbase.ResourceChecker(148): before: http.TestHttpServerLifecycle#testStoppedServerIsNotAlive
Thread=9, OpenFileDescriptor=201, MaxFileDescriptor=32768, SystemLoadAverage=112, ProcessCount=507,
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): Added global filter
'safety' (class=org.apache.hadoop.hbase.http.HttpServer$QuotingInputFilter)
2015-09-14 09:09:55,654 INFO  [Time-limited test] http.HttpServer(821): Added global filter
'clickjackingprevention' (class=org.apache.hadoop.hbase.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): Started SelectChannelConnector@localhost:49253
2015-09-14 09:09:55,684 INFO  [Time-limited test] log.Slf4jLog(67): Stopped SelectChannelConnector@localhost:0
2015-09-14 09:09:55,817 INFO  [main] hbase.ResourceChecker(172): after: http.TestHttpServerLifecycle#testStoppedServerIsNotAlive
Thread=9 (was 9), OpenFileDescriptor=201 (was 201), MaxFileDescriptor=32768 (was 32768), SystemLoadAverage=11
2015-09-14 09:09:55,847 INFO  [main] hbase.ResourceChecker(148): before: http.TestHttpServerLifecycle#testStoppingTwiceServerIsAllowed
Thread=9, OpenFileDescriptor=201, MaxFileDescriptor=32768, SystemLoadAverage=112, ProcessCount=507,
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): Added global filter
'safety' (class=org.apache.hadoop.hbase.http.HttpServer$QuotingInputFilter)
2015-09-14 09:09:55,880 INFO  [Time-limited test] http.HttpServer(821): Added global filter
'clickjackingprevention' (class=org.apache.hadoop.hbase.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): Started SelectChannelConnector@localhost:53449
2015-09-14 09:09:55,910 INFO  [Time-limited test] log.Slf4jLog(67): Stopped SelectChannelConnector@localhost:0
2015-09-14 09:09:56,038 INFO  [main] hbase.ResourceChecker(172): after: http.TestHttpServerLifecycle#testStoppingTwiceServerIsAllowed
Thread=9 (was 9), OpenFileDescriptor=201 (was 201), MaxFileDescriptor=32768 (was 32768), SystemLoadAvera
{code}

This test came over from hadoop. 

Looking at history, it usually passes up on apache jenkins so not disabling for now. Just
noting this failure.

https://builds.apache.org/view/H-L/view/HBase/job/PreCommit-HBASE-Build/15579/testReport/org.apache.hadoop.hbase.http/TestHttpServerLifecycle/history/



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message