TLS handshake error when bumping netty to 4.1.69.Final and tcnative to 2.0.44.Final #8605

dapengzhang0 · 2021-10-14T17:48:31Z

https://source.cloud.google.com/results/invocations/71e5d11c-8ed1-421a-86a0-b646f0eecb74/targets/grpc%2Fjava%2Fmaster%2Fpresubmit%2Fmacos/log

io.grpc.netty.ProtocolNegotiatorsTest > from_tls_clientAuthRequire_noClientCert FAILED
    expected:
        ssl exception
    but was:
        io exception
        Channel Pipeline: [SslHandler#0, ProtocolNegotiators$ClientTlsHandler#0, WriteBufferingAndExceptionHandler#0, DefaultChannelPipeline$TailContext#0]
        at io.grpc.netty.ProtocolNegotiatorsTest.from_tls_clientAuthRequire_noClientCert(ProtocolNegotiatorsTest.java:418)

io.grpc.netty.NettyClientTransportTest > tlsNegotiationServerExecutorShouldSucceed FAILED
    java.util.concurrent.TimeoutException: Waited 10 seconds (plus 10086801 nanoseconds delay) for SettableFuture@2fab9b61[status=PENDING]
        at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:508)
        at com.google.common.util.concurrent.AbstractFuture$TrustedFuture.get(AbstractFuture.java:111)
        at io.grpc.netty.NettyClientTransportTest$Rpc.waitForResponse(NettyClientTransportTest.java:847)
        at io.grpc.netty.NettyClientTransportTest.tlsNegotiationServerExecutorShouldSucceed(NettyClientTransportTest.java:720)

The text was updated successfully, but these errors were encountered:

ljnelson · 2021-11-03T17:12:27Z

(Lurking. Curious if this test failure is due in part or whole to Netty having turned off TLS 1.)

sanjaypujare · 2021-11-04T05:29:53Z

The first failure is because of error mismatch (io exception instead of ssl exception) which does not seem like a big issue.

The second one - I don't see any connection with disabling TLS1 but needs to be investigated

ljnelson · 2021-11-16T17:20:07Z

I've noticed the first failure doesn't occur (on my Mac) with JDK 8u301 in case that helps (if I understand right this project is still pinned on JDK 8).

I also now receive the following on the console when I run JAVA_HOME=$(/usr/libexec/java_home -v1.8) ./gradlew :grpc-netty:test:

[…]
> Task :grpc-netty:test
[jetty-alpn-agent][ info] alpn-boot not necessary for Java version: 1.8.0_301

…suggesting that the problem was more than a simple exception mismatch brought on by an upgrade and may indeed have to do with protocol negotiation. But I am still just speculating.

I'm still looking into the second issue.

ljnelson · 2021-11-18T16:51:10Z

More findings: I can make all our Helidon gRPC-related tests pass by setting the io.netty.handler.ssl.openssl.useTasks system property to false. I wonder if that would make the second failure here go away as well.

ljnelson · 2021-11-18T18:04:44Z

By adding:

systemProperty 'io.netty.handler.ssl.openssl.useTasks', 'false'

…to netty/build.gradle in the test block I make the remaining failure go away. This suggests an underlying problem in Netty.

ljnelson · 2021-11-18T18:20:52Z

Filed: netty/netty-tcnative#680

sanjaypujare · 2022-01-07T05:00:22Z

@normanmaurer this issue is still occurring on Macos and Windows. Will the fix for netty/netty-tcnative#680 (which is netty/netty#11854) not work on MacOS and Windows? What else is needed?

More information is available from tests in #8780 and #8813 . Some findings:

On MacOS before the netty upgrade (to 4.1.72.Final) it was using TLSv1.3 but after the upgrade it was using TLSv1.2. This causes a test to fail because of an unexpected exception (IOException instead of SSLException)
On Windows too we see the same behavior: dropping down to TLSv1.2 with the latest netty but using TLSv1.3 before the netty upgrade

normanmaurer · 2022-01-07T09:34:03Z

thats interesting.. there shouldn't be any other changes needed.

normanmaurer · 2022-01-07T14:02:42Z

@sanjaypujare can I somehow get the debug logs of netty for these failed test runs ?

sanjaypujare · 2022-01-07T16:46:19Z

@sanjaypujare can I somehow get the debug logs of netty for these failed test runs ?

Sure. I'll add what I have to this issue. If you want more info/background we can also communicate out-of-band.

sanjaypujare · 2022-01-07T16:57:03Z

This is the stack trace on our MacOS (Catalina) build machine for the failing test

grpc-java/netty/src/test/java/io/grpc/netty/ProtocolNegotiatorsTest.java

Line 410 in cccbcda

public void from_tls_clientAuthRequire_noClientCert() throws Exception {

(note I made temp changes to make it fail on all platforms and also some debug code)

io.grpc.StatusException: UNAVAILABLE: io exception
Channel Pipeline: [SslHandler#0, ProtocolNegotiators$ClientTlsHandler#0, WriteBufferingAndExceptionHandler#0, DefaultChannelPipeline$TailContext#0]
	at io.grpc.Status.asException(Status.java:543)
	at io.grpc.netty.ProtocolNegotiatorsTest.from_tls_clientAuthRequire_noClientCert(ProtocolNegotiatorsTest.java:424)
	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.RunBefores.evaluate(RunBefores.java:26)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	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)
Caused by: javax.net.ssl.SSLHandshakeException: error:10000410:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE
	at io.netty.handler.ssl.ReferenceCountedOpenSslEngine.shutdownWithError(ReferenceCountedOpenSslEngine.java:1074)
	at io.netty.handler.ssl.ReferenceCountedOpenSslEngine.sslReadErrorResult(ReferenceCountedOpenSslEngine.java:1365)
	at io.netty.handler.ssl.ReferenceCountedOpenSslEngine.unwrap(ReferenceCountedOpenSslEngine.java:1305)
	at io.netty.handler.ssl.ReferenceCountedOpenSslEngine.unwrap(ReferenceCountedOpenSslEngine.java:1392)
	at io.netty.handler.ssl.ReferenceCountedOpenSslEngine.unwrap(ReferenceCountedOpenSslEngine.java:1435)
	at io.netty.handler.ssl.SslHandler$SslEngineType$1.unwrap(SslHandler.java:221)
	at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1341)
	at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1234)
	at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1283)
	at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:507)
	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:446)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:722)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:658)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:584)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:496)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	... 1 more

I had added some more debug statements

session.getProtocol()=TLSv1.2
session.getProtocol()=TLSv1.2
cipherSuiteName=TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
session.getProtocol()=NONE
enabled protocols=[TLSv1, TLSv1.1, TLSv1.2]
supported protocols=[SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]

sanjaypujare · 2022-01-07T17:07:47Z

Similar debug info from the Windows build:

io.grpc.StatusException: UNAVAILABLE:
io exception Channel Pipeline: [SslHandler#0, ProtocolNegotiators$ClientTlsHandler#0, WriteBufferingAndExceptionHandler#0, DefaultChannelPipeline$TailContext#0]
 at io.grpc.Status.asException(Status.java:543)
 at io.grpc.netty.ProtocolNegotiatorsTest.from_tls_clientAuthRequire_noClientCert(ProtocolNegotiatorsTest.java:424)
 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.RunBefores.evaluate(RunBefores.java:26)
 at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
 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)
Caused by: javax.net.ssl.SSLHandshakeException: error:10000410:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE
 at io.netty.handler.ssl.ReferenceCountedOpenSslEngine.shutdownWithError(ReferenceCountedOpenSslEngine.java:1074)
 at io.netty.handler.ssl.ReferenceCountedOpenSslEngine.sslReadErrorResult(ReferenceCountedOpenSslEngine.java:1365)
 at io.netty.handler.ssl.ReferenceCountedOpenSslEngine.unwrap(ReferenceCountedOpenSslEngine.java:1305)
 at io.netty.handler.ssl.ReferenceCountedOpenSslEngine.unwrap(ReferenceCountedOpenSslEngine.java:1392)
 at io.netty.handler.ssl.ReferenceCountedOpenSslEngine.unwrap(ReferenceCountedOpenSslEngine.java:1435)
 at io.netty.handler.ssl.SslHandler$SslEngineType$1.unwrap(SslHandler.java:221)
 at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1341)
 at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1234)
 at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1283)
 at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:507)
 at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:446)
 at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
 at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
 at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
 at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
 at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
 at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:722)
 at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:658)
 at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:584)
 at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:496)
 at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
 at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
 at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
 ... 1 more

And the debug info

session.getProtocol()=TLSv1.2
session.getProtocol()=TLSv1.2
cipherSuiteName=TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
session.getProtocol()=NONE
enabled protocols=[TLSv1, TLSv1.1, TLSv1.2]
supported protocols=[SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]

Pls let me know what other info I can provide. Thanks a lot your help.

sergiitk · 2022-01-07T19:12:43Z

@normanmaurer I did some extra tests with Netty 4.1.69.final: #8815.

I don't think the root cause of the behavior we see right with from_tls_clientAuthRequire_noClientCert failing is turning on the tasks anymore. It's still a problem, but likely not caused by that leak you fixed.

Reproducing with 4.1.69

Linux fails on completely different test tlsNegotiationServerExecutorShouldSucceed
Mac fails both tlsNegotiationServerExecutorShouldSucceed AND from_tls_clientAuthRequire_noClientCert
2.1) However, from_tls_clientAuthRequire_noClientCert fails for a different reason too. As I understand, it's failing with HttpProxyConnectException, which accidentally happens to be extending IOException. So we still see io exception, but it's not a SSLException (which also extends IOException)
2.2) In io.grpc.netty.ProtocolNegotiatorsTest, I see SEVERE: LEAK: ByteBuf.release() was not called before it's garbage-collected - which is consistent, which is consistent with the problem @normanmaurer fixed in Fix reentrancy bug in SslHandler which can cause IllegalReferenceCoun… netty/netty#11854
All I said about Mac applies to Windows too

Reproducing with 4.1.69 and tasks off

tlsNegotiationServerExecutorShouldSucceed is now passes on all platforms
from_tls_clientAuthRequire_noClientCert fails on mac and windows.
2.1) Errors still look different that we see now, and fail on HttpProxyConnectException, not SSLException
2.2) No SEVERE: LEAK: ByteBuf.release() reports anymore

HttpProxyConnectException stderr:

Jan 07, 2022 10:44:46 AM io.netty.channel.DefaultChannelPipeline onUnhandledInboundException
WARNING: An exceptionCaught() event was fired, and it reached at the tail of the pipeline. It usually means the last handler in the pipeline did not handle the exception.
io.netty.handler.proxy.HttpProxyHandler$HttpProxyConnectException: http, none, local:httpproxy_500 => specialHost:314, status: 500 OMG
	at io.netty.handler.proxy.HttpProxyHandler.handleResponse(HttpProxyHandler.java:200)
	at io.netty.handler.proxy.ProxyHandler.channelRead(ProxyHandler.java:257)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436)
	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296)
	at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251)
	at io.netty.handler.proxy.HttpProxyHandler$HttpClientCodecWrapper.channelRead(HttpProxyHandler.java:272)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
	at io.netty.channel.local.LocalChannel.readInbound(LocalChannel.java:299)
	at io.netty.channel.local.LocalChannel.finishPeerRead0(LocalChannel.java:445)
	at io.netty.channel.local.LocalChannel.finishPeerRead(LocalChannel.java:391)
	at io.netty.channel.local.LocalChannel.doWrite(LocalChannel.java:385)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:949)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.flush(AbstractChannel.java:913)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.flush(DefaultChannelPipeline.java:1372)
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:750)
	at io.netty.channel.AbstractChannelHandlerContext.invokeWriteAndFlush(AbstractChannelHandlerContext.java:765)
	at io.netty.channel.AbstractChannelHandlerContext$WriteTask.run(AbstractChannelHandlerContext.java:1071)
	at io.netty.channel.DefaultEventLoop.run(DefaultEventLoop.java:54)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:748)

NoSuchElementException stderr:

Jan 07, 2022 10:44:46 AM io.netty.channel.DefaultChannelPipeline onUnhandledInboundException
WARNING: An exceptionCaught() event was fired, and it reached at the tail of the pipeline. It usually means the last handler in the pipeline did not handle the exception.
java.util.NoSuchElementException: ProtocolNegotiatorsTest$FakeGrpcHttp2ConnectionHandler#0
	at io.netty.channel.DefaultChannelPipeline.getContextOrDie(DefaultChannelPipeline.java:1073)
	at io.netty.channel.DefaultChannelPipeline.addBefore(DefaultChannelPipeline.java:248)
	at io.netty.channel.DefaultChannelPipeline.addBefore(DefaultChannelPipeline.java:237)
	at io.grpc.netty.ProtocolNegotiatorsTest$FakeGrpcHttp2ConnectionHandler.handleProtocolNegotiationCompleted(ProtocolNegotiatorsTest.java:1372)
	at io.grpc.netty.ProtocolNegotiators$GrpcNegotiationHandler.userEventTriggered(ProtocolNegotiators.java:920)
	at io.netty.channel.AbstractChannelHandlerContext.invokeUserEventTriggered(AbstractChannelHandlerContext.java:346)
	at io.netty.channel.AbstractChannelHandlerContext.invokeUserEventTriggered(AbstractChannelHandlerContext.java:332)
	at io.netty.channel.AbstractChannelHandlerContext.fireUserEventTriggered(AbstractChannelHandlerContext.java:324)
	at io.grpc.netty.ProtocolNegotiators$ProtocolNegotiationHandler.fireProtocolNegotiationEvent(ProtocolNegotiators.java:1090)
	at io.grpc.netty.ProtocolNegotiators$WaitUntilActiveHandler.protocolNegotiationEventTriggered(ProtocolNegotiators.java:1005)
	at io.grpc.netty.ProtocolNegotiators$ProtocolNegotiationHandler.userEventTriggered(ProtocolNegotiators.java:1061)
	at io.netty.channel.AbstractChannelHandlerContext.invokeUserEventTriggered(AbstractChannelHandlerContext.java:346)
	at io.netty.channel.AbstractChannelHandlerContext.invokeUserEventTriggered(AbstractChannelHandlerContext.java:332)
	at io.netty.channel.AbstractChannelHandlerContext.fireUserEventTriggered(AbstractChannelHandlerContext.java:324)
	at io.grpc.netty.ProtocolNegotiators$ProtocolNegotiationHandler.fireProtocolNegotiationEvent(ProtocolNegotiators.java:1090)
	at io.grpc.netty.ProtocolNegotiators$ProxyProtocolNegotiationHandler.userEventTriggered0(ProtocolNegotiators.java:536)
	at io.grpc.netty.ProtocolNegotiators$ProtocolNegotiationHandler.userEventTriggered(ProtocolNegotiators.java:1063)
	at io.netty.channel.AbstractChannelHandlerContext.invokeUserEventTriggered(AbstractChannelHandlerContext.java:346)
	at io.netty.channel.AbstractChannelHandlerContext.invokeUserEventTriggered(AbstractChannelHandlerContext.java:332)
	at io.netty.channel.AbstractChannelHandlerContext.fireUserEventTriggered(AbstractChannelHandlerContext.java:324)
	at io.netty.handler.proxy.ProxyHandler.setConnectSuccess(ProxyHandler.java:290)
	at io.netty.handler.proxy.ProxyHandler.channelRead(ProxyHandler.java:259)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436)
	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296)
	at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251)
	at io.netty.handler.proxy.HttpProxyHandler$HttpClientCodecWrapper.channelRead(HttpProxyHandler.java:272)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
	at io.netty.channel.local.LocalChannel.readInbound(LocalChannel.java:299)
	at io.netty.channel.local.LocalChannel.finishPeerRead0(LocalChannel.java:445)
	at io.netty.channel.local.LocalChannel.finishPeerRead(LocalChannel.java:391)
	at io.netty.channel.local.LocalChannel.doWrite(LocalChannel.java:385)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:949)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.flush(AbstractChannel.java:913)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.flush(DefaultChannelPipeline.java:1372)
	at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:750)
	at io.netty.channel.AbstractChannelHandlerContext.invokeWriteAndFlush(AbstractChannelHandlerContext.java:765)
	at io.netty.channel.AbstractChannelHandlerContext$WriteTask.run(AbstractChannelHandlerContext.java:1071)
	at io.netty.channel.DefaultEventLoop.run(DefaultEventLoop.java:54)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:748)

sergiitk · 2022-01-07T19:26:06Z

Correction: @ejona86 clarified that HttpProxyConnectException is unrelated and from a different test. I'm re-running 4.1.69 with tasks off and printing actual status error cause.

sergiitk · 2022-01-07T20:19:34Z

The error was

javax.net.ssl.SSLHandshakeException: error:10000410:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE
	at io.netty.handler.ssl.ReferenceCountedOpenSslEngine.shutdownWithError(ReferenceCountedOpenSslEngine.java:1074)
	at io.netty.handler.ssl.ReferenceCountedOpenSslEngine.sslReadErrorResult(ReferenceCountedOpenSslEngine.java:1365)

Which indicated TLS downgrade. Now we have an idea what's going on; @sanjaypujare will provide more info.

sanjaypujare · 2022-01-07T20:19:39Z

@sanjaypujare can I somehow get the debug logs of netty for these failed test runs ?

@normanmaurer I think we know what's going on so there is no need for you to look into it any more (thanks @ejona86!)

Basically this change of yours (netty/netty@fd47554#diff-e74d47f955fb4fbcb149ffbbddbc4d8e30b3fa425c0d7695537aa5498efe34cc) is causing a downgrade to TLSv1.2 on certain build machines of ours because of using an older JDK. So the test fails because of an unexpected exception. Now that we know what's going on (and there are no regressions in the dependencies) we will just modify the test.

sanjaypujare · 2022-01-07T20:21:25Z

Thanks @sergiitk for helping with the investigations. That was extremely helpful!

ejona86 · 2022-06-06T14:17:14Z

@sanjaypujare, is this resolved?

sanjaypujare · 2022-06-06T16:15:13Z

@ejona86 Yes. I think this change d7f951a#diff-fc866201c5932cf1dec945fc83bd251bdf942c65fc1f84e545e8d75f46942820R423 fixes this. Closing it....

dapengzhang0 mentioned this issue Oct 14, 2021

dep: bump netty to 4.1.69.Final and tcnative to 2.0.44.Final #8593

Closed

dapengzhang0 added this to the Next milestone Oct 14, 2021

dapengzhang0 mentioned this issue Oct 20, 2021

Need compatible versions for Netty 4.1.68+ , GRPC server and netty-tcnative-boringssl-static #8617

Closed

sanjaypujare self-assigned this Oct 21, 2021

ljnelson mentioned this issue Nov 9, 2021

Upgrades Netty to 4.1.70.Final helidon-io/helidon#3423

Closed

ljnelson mentioned this issue Nov 18, 2021

When use_tasks is true, Netty seemingly can supply a freed ByteBuf to SslHandler::decode netty/netty-tcnative#680

Closed

sanjaypujare closed this as completed Jun 6, 2022

ejona86 removed this from the Next milestone Jul 22, 2022

github-actions bot locked as resolved and limited conversation to collaborators Oct 21, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

TLS handshake error when bumping netty to 4.1.69.Final and tcnative to 2.0.44.Final #8605

TLS handshake error when bumping netty to 4.1.69.Final and tcnative to 2.0.44.Final #8605

dapengzhang0 commented Oct 14, 2021

ljnelson commented Nov 3, 2021

sanjaypujare commented Nov 4, 2021

ljnelson commented Nov 16, 2021 •

edited

ljnelson commented Nov 18, 2021

ljnelson commented Nov 18, 2021

ljnelson commented Nov 18, 2021

sanjaypujare commented Jan 7, 2022 •

edited

normanmaurer commented Jan 7, 2022

normanmaurer commented Jan 7, 2022

sanjaypujare commented Jan 7, 2022

sanjaypujare commented Jan 7, 2022 •

edited

sanjaypujare commented Jan 7, 2022

sergiitk commented Jan 7, 2022 •

edited

sergiitk commented Jan 7, 2022

sergiitk commented Jan 7, 2022

sanjaypujare commented Jan 7, 2022

sanjaypujare commented Jan 7, 2022

ejona86 commented Jun 6, 2022

sanjaypujare commented Jun 6, 2022

TLS handshake error when bumping netty to 4.1.69.Final and tcnative to 2.0.44.Final #8605

TLS handshake error when bumping netty to 4.1.69.Final and tcnative to 2.0.44.Final #8605

Comments

dapengzhang0 commented Oct 14, 2021

ljnelson commented Nov 3, 2021

sanjaypujare commented Nov 4, 2021

ljnelson commented Nov 16, 2021 • edited

ljnelson commented Nov 18, 2021

ljnelson commented Nov 18, 2021

ljnelson commented Nov 18, 2021

sanjaypujare commented Jan 7, 2022 • edited

normanmaurer commented Jan 7, 2022

normanmaurer commented Jan 7, 2022

sanjaypujare commented Jan 7, 2022

sanjaypujare commented Jan 7, 2022 • edited

sanjaypujare commented Jan 7, 2022

sergiitk commented Jan 7, 2022 • edited

Reproducing with 4.1.69

Reproducing with 4.1.69 and tasks off

sergiitk commented Jan 7, 2022

sergiitk commented Jan 7, 2022

sanjaypujare commented Jan 7, 2022

sanjaypujare commented Jan 7, 2022

ejona86 commented Jun 6, 2022

sanjaypujare commented Jun 6, 2022

ljnelson commented Nov 16, 2021 •

edited

sanjaypujare commented Jan 7, 2022 •

edited

sanjaypujare commented Jan 7, 2022 •

edited

sergiitk commented Jan 7, 2022 •

edited