Uploaded image for project: 'HBase'
  1. HBase
  2. HBASE-26074

testLogLevelByHttps/testLogLevelByHttpsWithSpnego consistently failing on branch-1

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Resolved
    • Major
    • Resolution: Fixed
    • 1.7.0
    • 1.7.1
    • test

    Description

      In prep-ing for 1.7.1, I noticed that this test has been consistently failing on branch-1 forever. 

      Regression
health checks / yetus jdk8 hadoop2 checks / org.apache.hadoop.hbase.http.log.TestLogLevel.testLogLevelByHttpsWithSpnego

Failing for the past 1 build (Since Failed#145 )
Took 0.79 sec.
Error Message
Expected to find 'Unexpected end of file from server' but got unexpected exception:java.net.SocketException: Connection reset
 at java.net.SocketInputStream.read(SocketInputStream.java:210)
 at java.net.SocketInputStream.read(SocketInputStream.java:141)
 at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
 at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
 at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
 at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:743)
 at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:678)
 at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:702)
 at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1593)
 at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1498)
 at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480)
 at org.apache.hadoop.security.authentication.client.KerberosAuthenticator.authenticate(KerberosAuthenticator.java:189)
 at org.apache.hadoop.security.authentication.client.AuthenticatedURL.openConnection(AuthenticatedURL.java:347)
 at org.apache.hadoop.hbase.http.log.LogLevel$CLI.connect(LogLevel.java:268)
 at org.apache.hadoop.hbase.http.log.LogLevel$CLI.process(LogLevel.java:284)
 at org.apache.hadoop.hbase.http.log.LogLevel$CLI.doGetLevel(LogLevel.java:227)
 at org.apache.hadoop.hbase.http.log.LogLevel$CLI.sendLogLevelRequest(LogLevel.java:123)
 at org.apache.hadoop.hbase.http.log.LogLevel$CLI.run(LogLevel.java:107)
 at org.apache.hadoop.hbase.http.log.TestLogLevel.getLevel(TestLogLevel.java:349)
 at org.apache.hadoop.hbase.http.log.TestLogLevel.access$000(TestLogLevel.java:68)
 at org.apache.hadoop.hbase.http.log.TestLogLevel$1.run(TestLogLevel.java:325)
 at org.apache.hadoop.hbase.http.log.TestLogLevel$1.run(TestLogLevel.java:322)
 at java.security.AccessController.doPrivileged(Native Method)
 at javax.security.auth.Subject.doAs(Subject.java:422)
 at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1844)
 at org.apache.hadoop.hbase.http.log.TestLogLevel.testDynamicLogLevel(TestLogLevel.java:322)
 at org.apache.hadoop.hbase.http.log.TestLogLevel.testDynamicLogLevel(TestLogLevel.java:277)
 at org.apache.hadoop.hbase.http.log.TestLogLevel.testLogLevelByHttpsWithSpnego(TestLogLevel.java:451)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
 at java.lang.reflect.Method.invoke(Method.java:498)
 at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
 at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
 at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
 at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
 at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298)
 at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292)
 at java.util.concurrent.FutureTask.run(FutureTask.java:266)
 at java.lang.Thread.run(Thread.java:748)
Stacktrace
java.lang.AssertionError: 
Expected to find 'Unexpected end of file from server' but got unexpected exception:java.net.SocketException: Connection reset
	at java.net.SocketInputStream.read(SocketInputStream.java:210)
	at java.net.SocketInputStream.read(SocketInputStream.java:141)
	at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
	at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
	at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
	at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:743)
	at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:678)
	at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:702)
	at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1593)
	at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1498)
	at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480)
	at org.apache.hadoop.security.authentication.client.KerberosAuthenticator.authenticate(KerberosAuthenticator.java:189)
	at org.apache.hadoop.security.authentication.client.AuthenticatedURL.openConnection(AuthenticatedURL.java:347)
	at org.apache.hadoop.hbase.http.log.LogLevel$CLI.connect(LogLevel.java:268)
	at org.apache.hadoop.hbase.http.log.LogLevel$CLI.process(LogLevel.java:284)
	at org.apache.hadoop.hbase.http.log.LogLevel$CLI.doGetLevel(LogLevel.java:227)
	at org.apache.hadoop.hbase.http.log.LogLevel$CLI.sendLogLevelRequest(LogLevel.java:123)
	at org.apache.hadoop.hbase.http.log.LogLevel$CLI.run(LogLevel.java:107)
	at org.apache.hadoop.hbase.http.log.TestLogLevel.getLevel(TestLogLevel.java:349)
	at org.apache.hadoop.hbase.http.log.TestLogLevel.access$000(TestLogLevel.java:68)
	at org.apache.hadoop.hbase.http.log.TestLogLevel$1.run(TestLogLevel.java:325)
	at org.apache.hadoop.hbase.http.log.TestLogLevel$1.run(TestLogLevel.java:322)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:422)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1844)
	at org.apache.hadoop.hbase.http.log.TestLogLevel.testDynamicLogLevel(TestLogLevel.java:322)
	at org.apache.hadoop.hbase.http.log.TestLogLevel.testDynamicLogLevel(TestLogLevel.java:277)
	at org.apache.hadoop.hbase.http.log.TestLogLevel.testLogLevelByHttpsWithSpnego(TestLogLevel.java:451)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298)
	at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.lang.Thread.run(Thread.java:748)

	at org.apache.hadoop.hbase.http.log.TestLogLevel.exceptionShouldContains(TestLogLevel.java:479)
	at org.apache.hadoop.hbase.http.log.TestLogLevel.testLogLevelByHttpsWithSpnego(TestLogLevel.java:456)
Caused by: java.net.SocketException: Connection reset
	at org.apache.hadoop.hbase.http.log.TestLogLevel.getLevel(TestLogLevel.java:349)
	at org.apache.hadoop.hbase.http.log.TestLogLevel.access$000(TestLogLevel.java:68)
	at org.apache.hadoop.hbase.http.log.TestLogLevel.testDynamicLogLevel(TestLogLevel.java:322)
	at org.apache.hadoop.hbase.http.log.TestLogLevel.testDynamicLogLevel(TestLogLevel.java:277)
	at org.apache.hadoop.hbase.http.log.TestLogLevel.testLogLevelByHttpsWithSpnego(TestLogLevel.java:451)
Standard Output
Connecting to https://localhost:34625/logLevel?log=org.apache.hadoop.hbase.http.log.TestLogLevel
Submitted Log Name: org.apache.hadoop.hbase.http.log.TestLogLevel
Log Class: org.apache.commons.logging.impl.Log4JLogger
Effective level: DEBUG
Connecting to https://localhost:34625/logLevel?log=org.apache.hadoop.hbase.http.log.TestLogLevel&level=DEBUG
Submitted Log Name: org.apache.hadoop.hbase.http.log.TestLogLevel
Log Class: org.apache.commons.logging.impl.Log4JLogger
Submitted Level: DEBUG
Setting Level to DEBUG ...
Effective level: DEBUG
Connecting to http://localhost:42799/logLevel?log=org.apache.hadoop.hbase.http.log.TestLogLevel
Standard Error
2021-07-08 13:56:31,715 INFO  [main] hbase.ResourceChecker(178): after: http.log.TestLogLevel#testErrorLogLevel Thread=17 (was 13)
Potentially hanging thread: NioProcessor-3
	sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
	sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
	sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
	sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
	sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
	org.apache.mina.transport.socket.nio.NioProcessor.select(NioProcessor.java:72)
	org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1077)
	org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
	java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	java.lang.Thread.run(Thread.java:748)

Potentially hanging thread: Keep-Alive-Timer
	java.lang.Thread.sleep(Native Method)
	sun.net.www.http.KeepAliveCache.run(KeepAliveCache.java:172)
	java.lang.Thread.run(Thread.java:748)

Potentially hanging thread: NioProcessor-2
	sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
	sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
	sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
	sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
	sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
	org.apache.mina.transport.socket.nio.NioProcessor.select(NioProcessor.java:72)
	org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1077)
	org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
	java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	java.lang.Thread.run(Thread.java:748)

Potentially hanging thread: NioProcessor-1
	sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
	sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
	sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
	sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
	sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
	org.apache.mina.transport.socket.nio.NioProcessor.select(NioProcessor.java:72)
	org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1077)
	org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
	java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	java.lang.Thread.run(Thread.java:748)
 - Thread LEAK? -, OpenFileDescriptor=280 (was 279) - OpenFileDescriptor LEAK? -, MaxFileDescriptor=1048576 (was 1048576), SystemLoadAverage=513 (was 428) - SystemLoadAverage LEAK? -, ProcessCount=7 (was 7), AvailableMemoryMB=2522 (was 2579), ConnectionCount=0 (was 0)
2021-07-08 13:56:31,737 INFO  [main] hbase.ResourceChecker(150): before: http.log.TestLogLevel#testLogLevelByHttpsWithSpnego Thread=17, OpenFileDescriptor=280, MaxFileDescriptor=1048576, SystemLoadAverage=513, ProcessCount=7, AvailableMemoryMB=2521, ConnectionCount=0
2021-07-08 13:56:31,744 INFO  [Time-limited test] http.HttpRequestLog(69): Http request log for http.requests... is not defined
2021-07-08 13:56:31,748 INFO  [Time-limited test] http.HttpServer(881): Added global filter 'safety' (class=org.apache.hadoop.hbase.http.HttpServer$QuotingInputFilter)
2021-07-08 13:56:31,748 INFO  [Time-limited test] http.HttpServer(881): Added global filter 'clickjackingprevention' (class=org.apache.hadoop.hbase.http.ClickjackingPreventionFilter)
2021-07-08 13:56:31,749 INFO  [Time-limited test] http.HttpServer(739): ASYNC_PROFILER_HOME environment variable and async.profiler.home system property not specified. Disabling /prof endpoint.
2021-07-08 13:56:31,749 INFO  [Time-limited test] http.HttpServer(881): Added global filter 'SpnegoFilter' (class=org.apache.hadoop.security.authentication.server.AuthenticationFilter)
2021-07-08 13:56:31,801 INFO  [Time-limited test] http.HttpServer(1112): Jetty bound to port 34625
2021-07-08 13:56:31,803 INFO  [Time-limited test] log.Slf4jLog(67): jetty-6.1.26
2021-07-08 13:56:31,848 INFO  [Time-limited test] log.Slf4jLog(67): Started SslSocketConnectorSecure@localhost:34625
2021-07-08 13:56:32,154 WARN  [NioProcessor-2] protocol.KerberosProtocolHandler(241): KDC cannot accommodate requested option (13)
2021-07-08 13:56:32,154 WARN  [NioProcessor-2] protocol.KerberosProtocolHandler(242): KDC cannot accommodate requested option (13)
2021-07-08 13:56:32,287 WARN  [NioProcessor-1] protocol.KerberosProtocolHandler(241): KDC cannot accommodate requested option (13)
2021-07-08 13:56:32,287 WARN  [NioProcessor-1] protocol.KerberosProtocolHandler(242): KDC cannot accommodate requested option (13)
2021-07-08 13:56:32,338 INFO  [Time-limited test] log.Slf4jLog(67): Stopped SslSocketConnectorSecure@localhost:0
2021-07-08 13:56:32,445 INFO  [Time-limited test] http.HttpRequestLog(69): Http request log for http.requests... is not defined
2021-07-08 13:56:32,445 INFO  [Time-limited test] http.HttpServer(881): Added global filter 'safety' (class=org.apache.hadoop.hbase.http.HttpServer$QuotingInputFilter)
2021-07-08 13:56:32,445 INFO  [Time-limited test] http.HttpServer(881): Added global filter 'clickjackingprevention' (class=org.apache.hadoop.hbase.http.ClickjackingPreventionFilter)
2021-07-08 13:56:32,446 INFO  [Time-limited test] http.HttpServer(739): ASYNC_PROFILER_HOME environment variable and async.profiler.home system property not specified. Disabling /prof endpoint.
2021-07-08 13:56:32,447 INFO  [Time-limited test] http.HttpServer(881): Added global filter 'SpnegoFilter' (class=org.apache.hadoop.security.authentication.server.AuthenticationFilter)
2021-07-08 13:56:32,448 INFO  [Time-limited test] http.HttpServer(1112): Jetty bound to port 42799
2021-07-08 13:56:32,448 INFO  [Time-limited test] log.Slf4jLog(67): jetty-6.1.26
2021-07-08 13:56:32,483 INFO  [Time-limited test] log.Slf4jLog(67): Started SslSocketConnectorSecure@localhost:42799
2021-07-08 13:56:32,506 WARN  [1853592968@qtp-1232647843-0] log.Slf4jLog(89): EXCEPTION 
javax.net.ssl.SSLException: Unsupported or unrecognized SSL message
	at sun.security.ssl.SSLSocketInputRecord.handleUnknownRecord(SSLSocketInputRecord.java:440)
	at sun.security.ssl.SSLSocketInputRecord.decode(SSLSocketInputRecord.java:175)
	at sun.security.ssl.SSLTransport.decode(SSLTransport.java:110)
	at sun.security.ssl.SSLSocketImpl.decode(SSLSocketImpl.java:1197)
	at sun.security.ssl.SSLSocketImpl.readHandshakeRecord(SSLSocketImpl.java:1106)
	at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:398)
	at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:370)
	at org.mortbay.jetty.security.SslSocketConnector$SslConnection.run(SslSocketConnector.java:708)
	at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)
2021-07-08 13:56:32,510 WARN  [1853592968@qtp-1232647843-0] log.Slf4jLog(89): EXCEPTION 
javax.net.ssl.SSLException: Unsupported or unrecognized SSL message
	at sun.security.ssl.SSLSocketInputRecord.handleUnknownRecord(SSLSocketInputRecord.java:440)
	at sun.security.ssl.SSLSocketInputRecord.decode(SSLSocketInputRecord.java:175)
	at sun.security.ssl.SSLTransport.decode(SSLTransport.java:110)
	at sun.security.ssl.SSLSocketImpl.decode(SSLSocketImpl.java:1197)
	at sun.security.ssl.SSLSocketImpl.readHandshakeRecord(SSLSocketImpl.java:1106)
	at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:398)
	at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:370)
	at org.mortbay.jetty.security.SslSocketConnector$SslConnection.run(SslSocketConnector.java:708)
	at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)
2021-07-08 13:56:32,511 INFO  [Time-limited test] log.Slf4jLog(67): Stopped SslSocketConnectorSecure@localhost:0
REST API
CloudBees CI Client Master 2.263.4.2-rolling

      Attachments

        Issue Links

          is related to

          Bug - A problem which impairs or prevents the functions of the product. HBASE-21048 Get LogLevel is not working from console in secure environment

          • Major - Major loss of function.
          • Resolved

          New Feature - A new feature of the product, which has yet to be developed. HBASE-22184 [security] Support get|set LogLevel in HTTPS mode

          • Major - Major loss of function.
          • Resolved

          Test - A new unit, integration or system test. HBASE-22545 TestLogLevel broken

          • Major - Major loss of function.
          • Resolved
          links to

          Web Link GitHub Pull Request #3466

          Activity

            People

              bharathv Bharath Vissapragada
              bharathv Bharath Vissapragada
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: