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)
