initChannel results in System.err (two way ssl authentication)

[trondarild-lode-tobiassen-heidelberg]

Expected behavior: SSL request as coded

Actual behavior: No SSL Request - System err.

Steps to reproduce: Copy code in https://stackoverflow.com/questions/51431692/w-system-err-at-io-netty-channel-abstractchannelabstractunsafe-ensureopen to initChannel

Minimal yet complete reproducer code (or URL to code):

https://stackoverflow.com/questions/51431692/w-system-err-at-io-netty-channel-abstractchannelabstractunsafe-ensureopen

Netty version: 4.1.28.Final

JVM version (e.g. java -version) Android 8.0

OS version (e.g. uname -a)

Android 8.0

[Mr00Anderson]

would help to see a stacktrace

[trondarild-lode-tobiassen-heidelberg]

Unfortunately, all that is available is the System.err.

[Mr00Anderson]

I looked at your stackoverflow and I feel like something is missing. Netty normally using a logging framework sl4j. I have not seen a printout as you have shown in the past when I have caused SSL Errors. Can you provide you code in a complete test case. Providing runnable code (doesn't have to be your private code) you can mock the private stuff; will allow us to run and actually re-produce the bug on our systems.

Error you posted on SO:
System.err: 07-19 22:30:16.437 7609-7638/xx.xxxxxxx.sipclient W/System.err: java.nio.channels.ClosedChannelException 07-19 22:30:16.437 7609-7638/xx.xxxxxxx.sipclient W/System.err: at io.netty.channel.AbstractChannel$AbstractUnsafe.ensureOpen(...)(Unknown Source)

[trondarild-lode-tobiassen-heidelberg]

This is the output get:
07-28 21:34:15.832 30729-30749/xx.xxxxx.sipclient W/System.err: java.nio.channels.ClosedChannelException
07-28 21:34:15.832 30729-30749/xx.xxxxxxx.sipclient W/System.err: at io.netty.channel.AbstractChannel$AbstractUnsafe.ensureOpen(...)(Unknown Source)

I have used slf4j and log4j in my lib used on Android but not been able to make it work. Requires some gradle fiddling because Android has it's own log/slf4j lib.

I will make a junit test running on java 8 and we will see any difference then. I will post the results no matter if I am able to resolve things myself.

Thanks for your input.

[trondarild-lode-tobiassen-heidelberg]

Before I post the project with the JUnit test I want to know if this stacktrace helps (I had to try-catch the contents of initChannel):

java.lang.IllegalArgumentException: Duplicate handler name: ssl
at io.netty.channel.DefaultChannelPipeline.checkDuplicateName(DefaultChannelPipeline.java:1101)
at io.netty.channel.DefaultChannelPipeline.filterName(DefaultChannelPipeline.java:302)
at io.netty.channel.DefaultChannelPipeline.addLast(DefaultChannelPipeline.java:210)
at io.netty.channel.DefaultChannelPipeline.addLast(DefaultChannelPipeline.java:201)
at xx.xxxxxx.test.common.NettySSLTwoWayAuthenticationTest$1.initChannel(NettySSLTwoWayAuthenticationTest.java:91)
at xx.xxxxxxxx.test.common.NettySSLTwoWayAuthenticationTest$1.initChannel(NettySSLTwoWayAuthenticationTest.java:1)
at io.netty.channel.ChannelInitializer.initChannel(ChannelInitializer.java:115)
at io.netty.channel.ChannelInitializer.handlerAdded(ChannelInitializer.java:107)
at io.netty.channel.DefaultChannelPipeline.callHandlerAdded0(DefaultChannelPipeline.java:637)
at io.netty.channel.DefaultChannelPipeline.addLast(DefaultChannelPipeline.java:235)
at io.netty.channel.DefaultChannelPipeline.addLast(DefaultChannelPipeline.java:201)
at xx.xxxxx.test.common.NettySSLTwoWayAuthenticationTest$1.initChannel(NettySSLTwoWayAuthenticationTest.java:92)
at xx.xxxxxxx.test.common.NettySSLTwoWayAuthenticationTest$1.initChannel(NettySSLTwoWayAuthenticationTest.java:1)
at io.netty.channel.ChannelInitializer.initChannel(ChannelInitializer.java:115)
at io.netty.channel.ChannelInitializer.handlerAdded(ChannelInitializer.java:107)
at io.netty.channel.DefaultChannelPipeline.callHandlerAdded0(DefaultChannelPipeline.java:637)
at io.netty.channel.DefaultChannelPipeline.access$000(DefaultChannelPipeline.java:46)
at io.netty.channel.DefaultChannelPipeline$PendingHandlerAddedTask.execute(DefaultChannelPipeline.java:1487)
at io.netty.channel.DefaultChannelPipeline.callHandlerAddedForAllHandlers(DefaultChannelPipeline.java:1161)
at io.netty.channel.DefaultChannelPipeline.invokeHandlerAddedIfNeeded(DefaultChannelPipeline.java:686)
at io.netty.channel.AbstractChannel$AbstractUnsafe.register0(AbstractChannel.java:510)
at io.netty.channel.AbstractChannel$AbstractUnsafe.access$200(AbstractChannel.java:423)
at io.netty.channel.AbstractChannel$AbstractUnsafe$1.run(AbstractChannel.java:482)
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:404)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:464)
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:884)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(Thread.java:748)

[trondarild-lode-tobiassen-heidelberg]

This is line 91:
ch.pipeline().addLast("ssl", new SslHandler(engine, false));

[Mr00Anderson]

Yes that helps a lot. Found your issue already. So something is up because your handler is being added twice it appears java.lang.IllegalArgumentException: Duplicate handler name: ssl Netty Pipline will throw this exception if a handler is already in that pipeline with the same name. Also I found with Netty in my experience is to use try/catch in various spots. Sometimes without it tracking issues can be tough as well as may not pop up.

[trondarild-lode-tobiassen-heidelberg]

Is it not legal to add both keyManager and trustManager to sslBuilder? That's the only way I can see I have added something twice. Line 91 is the only place I add a channelhandler named "ssl".

[Mr00Anderson]

Use "```" before and after or highlight your code and select code so everyone can see it. I know you put it on stack overflow; kinda of a pain in the ass to go back and fourth. I copied your code from SO for everyone watching.

SslContextBuilder sslBuilder = SslContextBuilder.forClient();
                    SslContext cont2 = null;
                    TrustManagerFactory trustManagerFactory = TrustManagerFactory
                            .getInstance(TrustManagerFactory.getDefaultAlgorithm());
                    // truststore
                    KeyStore clientKeyStore = KeyStore.getInstance("JKS");
                    clientKeyStore.load(null, SipListener.KEYSTORE_PASSWORD.toCharArray());
                    for (Cert clientCertCert : sipSettingsBean.getSipSettingsServerBeans().get(0).getCerts()) {
                        Certificate clientCert = CertificateFactory.getInstance("X.509")
                                .generateCertificate(new ByteArrayInputStream(
                                        clientCertCert.getCert().getBytes()));
                        clientKeyStore.setCertificateEntry(
                                clientCertCert.getAlias(), clientCert);
                    }

                    trustManagerFactory.init(clientKeyStore);
                    sslBuilder.trustManager(trustManagerFactory);
                    KeyManagerFactory keyManagerFactory = KeyManagerFactory
                            .getInstance(KeyManagerFactory.getDefaultAlgorithm());
                    KeyStore serverKeyStore = KeyStore.getInstance("JKS");
                    serverKeyStore.load(
                            new ByteArrayInputStream(
                                    sipSettingsBean.getSipSettingsServerBeans().get(0).getKeystore().getBytes()),
                            SipListener.KEYSTORE_PASSWORD.toCharArray());
                    if (!serverKeyStore.isKeyEntry(sipSettingsBean.getSipSettingsServerBeans().get(0).getKeystoreAlias()))
                        throw new IllegalArgumentException(
                                "Keystore file has no matching key for given alias.");
                    keyManagerFactory.init(serverKeyStore,
                            SipListener.KEYSTORE_PASSWORD.toCharArray());
                    sslBuilder.keyManager(keyManagerFactory);
                    cont2 = sslBuilder.build();
                    SSLEngine engine = cont2.newEngine(ch.alloc(), toHostname,
                            portDestination);
                    engine.setEnabledProtocols(new String[]{"TLSv1.2"});
                    ch.pipeline().addLast("ssl", new SslHandler(engine, false));
                    ch.pipeline().addLast("handler",
                            simpleChannelInboundHandlerRegisterTCP);

[Mr00Anderson]

Try this... use SslContext.newHandler(); Ignore my nettySslCredentialts that's my own class. But the point is to use the contexts to grab a new handler. SslContext use the channel or channel handler context .alloc() which gets the default bytebuf allocater use in the channel. Or if you use your own.

           SslContext sslContext;
           SslHandler sslHandler;

           sslContext = nettySslCredentials.buildContext();
           sslHandler = sslContext.newHandler(c.alloc());

           p.addLast(SSL_HANDLER_STRING, sslHandler);
   

[trondarild-lode-tobiassen-heidelberg]

Hmmm ... using the test itself as the inbound handler was not a good idea. The test ran twice and the exception resulted. Now, with the inbound handler a separate class the test runs fine. I am able to connect.

[Mr00Anderson]

Cool then see you on the flip side; if all is working. Probably want to close this issue as well.

[trondarild-lode-tobiassen-heidelberg]

Maybe you could fix that no output/stacktrace print is shown from inside initChannel? Anonymous class?

[Mr00Anderson]

I am not a active participant to writing fixes to the code base; just try to read through the source code to help those who do not know how to or take the time themselves to review the source code; also answering questions that are not necessary and issue with the library itself. This may be related to Issues 6096. You would have to check and if it is merge this with that issue. I also do not seem to have issues with exceptions popping from my init channel; it throws exceptions for me.

[trondarild-lode-tobiassen-heidelberg]

Thanks. Seems 6096 is the same thing.

[trondarild-lode-tobiassen-heidelberg]

And comment: This happens on Android.

[normanmaurer]

I added a test for this to show it works as expected in the latest netty release: #8188

Closing the issue