Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Recent commit breaks Mutual TLS #6796

Closed
rkapsi opened this issue May 31, 2017 · 12 comments
Closed

Recent commit breaks Mutual TLS #6796

rkapsi opened this issue May 31, 2017 · 12 comments
Assignees
Labels

Comments

@rkapsi
Copy link
Member

rkapsi commented May 31, 2017

Commit f20063d appears to break Mutual TLS in the sense that the connection just hangs. There're no Exceptions as far as I can tell and the only failure I'm getting is when the events in SslHandler#channelInactive(...) fire.

Interestingly, the problem occurs only in our production environment (which has more load, latencies and RTTs between servers). The problem doesn't occur on my dev workstation (i.e. unable to reproduce in the form of a unit test).

Reverting the commit fixes the problem for me.

Expected behavior

Actual behavior

Steps to reproduce

Minimal yet complete reproducer code (or URL to code)

Netty version

4.1.12.Final-SNAPSHOT w/ TCN 2.0.2.Final-SNAPSHOT (openssl-static)

JVM version (e.g. java -version)

OS version (e.g. uname -a)

@normanmaurer
Copy link
Member

@rkapsi thanks for reporting.... I will have a look but if we can not borrow it down it may be the easiest to just revert the change. @Scottmitch WDYT?

@johnou
Copy link
Contributor

johnou commented May 31, 2017

@rkapsi apologies for the hijack 😜 but this issue looks interesting for our project @normanmaurer how's it looking time wise for the next tcnative / netty release to address the SSL fixes in particular the memory leak?

@normanmaurer
Copy link
Member

@johnou very soon. That said the leak will only affect people who are creating and destroying *OpenSslContextobjects very frequently. That should be very rare ;)

@slandelle
Copy link
Contributor

only affect people who are creating and destroying *OpenSslContextobjects very frequently. That should be very rare ;)

Well, I am :)

@Scottmitch
Copy link
Member

Thanks for reporting @rkapsi ... This interface is a bit fragile and I wouldn't expect calling wrap again to generate more data (considering the engine said it needed a unwrap). Do you see the same behavior with the JDK ssl provider, and would you be able to report some debug info on the status of the subsequent call to unwrap (see below). I want to make sure the issue isn't in the OpenSslEngine if possible.

diff --git a/handler/src/main/java/io/netty/handler/ssl/SslHandler.java b/handler/src/main/java/io/netty/handler/ssl/SslHandler.java
index c05496466..6a5d28309 100644
--- a/handler/src/main/java/io/netty/handler/ssl/SslHandler.java
+++ b/handler/src/main/java/io/netty/handler/ssl/SslHandler.java
@@ -769,6 +769,7 @@ public class SslHandler extends ByteToMessageDecoder implements ChannelOutboundH
     private void wrapNonAppData(ChannelHandlerContext ctx, boolean inUnwrap) throws SSLException {
         ByteBuf out = null;
         ByteBufAllocator alloc = ctx.alloc();
+        boolean previousNeedUnwrap = false;
         try {
             // Only continue to loop if the handler was not removed in the meantime.
             // See https://github.com/netty/netty/issues/5860
@@ -779,8 +780,13 @@ public class SslHandler extends ByteToMessageDecoder implements ChannelOutboundH
                     // If this is not enough we will increase the buffer in wrap(...).
                     out = allocateOutNetBuf(ctx, 2048, 1);
                 }
+
                 SSLEngineResult result = wrap(alloc, engine, Unpooled.EMPTY_BUFFER, out);
 
+                if (previousNeedUnwrap) {
+                    previousNeedUnwrap = false;
+                    logger.info("previous status was unwrap, new status is {}", result);
+                }
                 if (result.bytesProduced() > 0) {
                     ctx.write(out);
                     if (inUnwrap) {
@@ -797,14 +803,11 @@ public class SslHandler extends ByteToMessageDecoder implements ChannelOutboundH
                         runDelegatedTasks();
                         break;
                     case NEED_UNWRAP:
-                        if (inUnwrap) {
-                            // If we asked for a wrap, the engine requested an unwrap, and we are in unwrap there is
-                            // no use in trying to call wrap again because we have already attempted (or will after we
-                            // return) to feed more data to the engine.
-                            return;
+                        previousNeedUnwrap = true;
+                        if (!inUnwrap) {
+                            unwrapNonAppData(ctx);
                         }
 
-                        unwrapNonAppData(ctx);
                         break;
                     case NEED_WRAP:
                         break;

@Scottmitch Scottmitch self-assigned this May 31, 2017
@rkapsi
Copy link
Member Author

rkapsi commented May 31, 2017

@Scottmitch I'll test JDK and the patch tomorrow.

@rkapsi
Copy link
Member Author

rkapsi commented Jun 1, 2017

@Scottmitch here are the results:

4.1.12-SNAPSHOT + OPENSSL: doesn't work
4.1.12-SNAPSHOT + JDK: works

4.1.12-HEAD w/ patch + OPENSSL: works

2017-06-01 12:54:23,710 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:23,858 [ConnectorThread-7] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:23,914 [ConnectorThread-2] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:24,022 [ConnectorThread-7] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,022 [ConnectorThread-2] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,022 [ConnectorThread-7] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,022 [ConnectorThread-2] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,023 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,024 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,030 [ConnectorThread-2] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,031 [ConnectorThread-2] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:24,031 [ConnectorThread-2] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:24,031 [ConnectorThread-7] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,032 [ConnectorThread-7] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:24,038 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,038 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:24,038 [ConnectorThread-7] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:24,038 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:24,055 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:24,093 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,094 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,098 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,099 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:24,099 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:24,147 [ConnectorThread-4] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:24,179 [ConnectorThread-4] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,180 [ConnectorThread-4] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,183 [ConnectorThread-4] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,183 [ConnectorThread-4] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:24,183 [ConnectorThread-4] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:24,539 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:24,562 [ConnectorThread-6] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:24,575 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,575 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,578 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,579 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:24,579 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:24,593 [ConnectorThread-6] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,594 [ConnectorThread-6] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,597 [ConnectorThread-6] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,597 [ConnectorThread-6] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:24,597 [ConnectorThread-6] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:24,742 [ConnectorThread-8] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:24,764 [ConnectorThread-8] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,764 [ConnectorThread-8] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,767 [ConnectorThread-8] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,767 [ConnectorThread-8] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:24,768 [ConnectorThread-8] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:24,853 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:24,885 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,885 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,891 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:24,891 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:24,892 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:24,993 [ConnectorThread-7] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:25,015 [ConnectorThread-7] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:25,015 [ConnectorThread-7] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:25,018 [ConnectorThread-7] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:25,018 [ConnectorThread-7] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:25,018 [ConnectorThread-7] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:25,135 [ConnectorThread-12] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:25,169 [ConnectorThread-12] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:25,169 [ConnectorThread-12] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:25,176 [ConnectorThread-12] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:25,176 [ConnectorThread-12] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:25,177 [ConnectorThread-12] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:25,452 [ConnectorThread-10] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:25,497 [ConnectorThread-10] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:25,497 [ConnectorThread-10] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:25,501 [ConnectorThread-10] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:25,502 [ConnectorThread-10] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:25,502 [ConnectorThread-10] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:25,854 [ConnectorThread-14] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:25,904 [ConnectorThread-14] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:25,904 [ConnectorThread-14] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:25,910 [ConnectorThread-14] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:25,910 [ConnectorThread-14] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:25,910 [ConnectorThread-14] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:25,946 [ConnectorThread-4] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:25,969 [ConnectorThread-4] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:25,969 [ConnectorThread-4] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:25,975 [ConnectorThread-4] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:25,975 [ConnectorThread-4] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:25,976 [ConnectorThread-4] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:26,116 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:26,139 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:26,139 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:26,145 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:26,145 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:26,145 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:27,122 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:27,155 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:27,155 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:27,161 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:27,162 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:27,162 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:27,218 [ConnectorThread-8] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:27,253 [ConnectorThread-8] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:27,253 [ConnectorThread-8] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:27,261 [ConnectorThread-8] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:27,262 [ConnectorThread-8] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:27,262 [ConnectorThread-8] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:27,276 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:27,309 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:27,309 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:27,313 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:27,313 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:27,313 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:27,359 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:27,392 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:27,392 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:27,397 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:27,397 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:27,397 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:27,907 [ConnectorThread-0] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:54:27,935 [ConnectorThread-0] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:27,935 [ConnectorThread-0] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:27,944 [ConnectorThread-0] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 2138
2017-06-01 12:54:27,945 [ConnectorThread-0] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 159
2017-06-01 12:54:27,945 [ConnectorThread-0] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0

4.1.12-HEAD w/ patch + JDK: works

2017-06-01 12:58:46,252 [ConnectorThread-9] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:46,252 [ConnectorThread-0] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:46,252 [ConnectorThread-10] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:46,577 [ConnectorThread-0] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:46,577 [ConnectorThread-9] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:46,583 [ConnectorThread-10] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:46,696 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:46,735 [ConnectorThread-11] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:46,748 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:46,781 [ConnectorThread-0] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:46,784 [ConnectorThread-11] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:46,834 [ConnectorThread-0] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:47,234 [ConnectorThread-1] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:47,277 [ConnectorThread-1] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:47,691 [ConnectorThread-13] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:47,699 [ConnectorThread-12] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:47,739 [ConnectorThread-3] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:47,742 [ConnectorThread-13] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:47,752 [ConnectorThread-12] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:47,787 [ConnectorThread-3] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:47,951 [ConnectorThread-13] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:48,003 [ConnectorThread-13] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:48,514 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:48,550 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:48,662 [ConnectorThread-8] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:48,721 [ConnectorThread-3] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:48,722 [ConnectorThread-8] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:48,762 [ConnectorThread-3] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:48,921 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:48,968 [ConnectorThread-5] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:49,286 [ConnectorThread-10] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:49,340 [ConnectorThread-10] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:49,968 [ConnectorThread-10] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:50,020 [ConnectorThread-10] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:50,199 [ConnectorThread-10] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:50,295 [ConnectorThread-10] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:50,538 [ConnectorThread-2] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:50,553 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:50,585 [ConnectorThread-2] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-01 12:58:50,608 [ConnectorThread-15] SslHandler INFO : previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0

@rkapsi
Copy link
Member Author

rkapsi commented Jun 1, 2017

I should note that this is our Netty app (acting as client) trying to connect to something like Tomcat, Jetty using mutual TLS.

@Scottmitch
Copy link
Member

thanks @rkapsi ... so looks like the behavior of OpenSslEngine is not consistent with the JDK engine ... let me investigate. @normanmaurer - if this is holding up a release let me know and I can revert and work out alternative means of investigation.

@Scottmitch
Copy link
Member

Scottmitch commented Jun 1, 2017

@rkapsi - I may have found a contributing factor to the inconstant behavior in the OpenSslEngine ... can you run OpenSslEngine with PR #6803 and report the same log statements back?

@rkapsi
Copy link
Member Author

rkapsi commented Jun 2, 2017

@Scottmitch here are the results for #6803

openssl_wrap_status w/ OPENSSL: works

2017-06-02 11:55:17,506 [ConnectorThread-6] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:17,506 [ConnectorThread-9] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:17,507 [ConnectorThread-4] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:17,666 [ConnectorThread-2] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:17,917 [ConnectorThread-7] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:18,012 [ConnectorThread-7] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:18,014 [ConnectorThread-6] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:18,027 [ConnectorThread-2] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:18,029 [ConnectorThread-9] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:18,036 [ConnectorThread-4] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:18,064 [ConnectorThread-2] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:18,104 [ConnectorThread-2] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:18,681 [ConnectorThread-1] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:18,684 [ConnectorThread-2] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:18,715 [ConnectorThread-1] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:18,721 [ConnectorThread-2] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:19,942 [ConnectorThread-5] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:19,985 [ConnectorThread-5] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:20,279 [ConnectorThread-5] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:20,319 [ConnectorThread-5] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:20,354 [ConnectorThread-14] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:20,395 [ConnectorThread-14] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:20,928 [ConnectorThread-5] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:20,967 [ConnectorThread-5] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:21,191 [ConnectorThread-6] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:21,225 [ConnectorThread-6] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:21,304 [ConnectorThread-5] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:21,332 [ConnectorThread-5] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:21,431 [ConnectorThread-1] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:21,460 [ConnectorThread-1] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:21,650 [ConnectorThread-10] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:21,684 [ConnectorThread-5] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:21,699 [ConnectorThread-10] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:21,722 [ConnectorThread-5] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:21,811 [ConnectorThread-15] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:21,851 [ConnectorThread-15] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:21,902 [ConnectorThread-2] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:21,938 [ConnectorThread-2] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:21,981 [ConnectorThread-15] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:55:22,019 [ConnectorThread-15] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0

openssl_wrap_status w/ JDK: works

2017-06-02 11:50:19,115 [ConnectorThread-7] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:19,148 [ConnectorThread-5] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:19,409 [ConnectorThread-5] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:19,413 [ConnectorThread-7] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:20,349 [ConnectorThread-3] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:20,412 [ConnectorThread-3] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:20,496 [ConnectorThread-1] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:20,543 [ConnectorThread-9] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:20,550 [ConnectorThread-1] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:20,589 [ConnectorThread-9] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:20,679 [ConnectorThread-5] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:20,728 [ConnectorThread-5] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:20,764 [ConnectorThread-3] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:20,775 [ConnectorThread-4] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:20,817 [ConnectorThread-3] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:20,841 [ConnectorThread-4] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:20,844 [ConnectorThread-3] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:20,905 [ConnectorThread-3] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:21,029 [ConnectorThread-0] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:21,082 [ConnectorThread-0] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:21,180 [ConnectorThread-3] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:21,253 [ConnectorThread-3] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:21,271 [ConnectorThread-9] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:21,331 [ConnectorThread-9] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:21,466 [ConnectorThread-15] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:21,515 [ConnectorThread-15] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:22,050 [ConnectorThread-13] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:22,111 [ConnectorThread-13] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:22,380 [ConnectorThread-10] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:22,454 [ConnectorThread-10] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:22,510 [ConnectorThread-15] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:22,569 [ConnectorThread-15] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:22,646 [ConnectorThread-5] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:22,708 [ConnectorThread-5] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:23,162 [ConnectorThread-7] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:23,220 [ConnectorThread-7] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:23,238 [ConnectorThread-10] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:23,293 [ConnectorThread-10] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:23,337 [ConnectorThread-14] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0
2017-06-02 11:50:23,373 [ConnectorThread-14] SslHandler INFO : ==previous status was unwrap, new status is Status = OK HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 0

Scottmitch added a commit to Scottmitch/netty that referenced this issue Jun 2, 2017
Motivation:
If the destination buffer is completely filled during a call to OpenSslEngine#wrap(..) we may return NEED_UNWRAP because there is no data pending in the SSL buffers. However during a handshake if the SSL buffers were just drained, and filled up the destination buffer it is possible OpenSSL may produce more data on the next call to SSL_write. This means we should keep trying to call SSL_write as long as the destination buffer is filled and only return NEED_UNWRAP when the destination buffer is not full and there is no data pending in OpenSSL's buffers.

Modifications:
- If the handshake produces data in OpenSslEngine#wrap(..) we should return NEED_WRAP if the destination buffer is completely filled

Result:
OpenSslEngine returns the correct handshake status from wrap().
Fixes netty#6796.
Scottmitch added a commit that referenced this issue Jun 2, 2017
Motivation:
If the destination buffer is completely filled during a call to OpenSslEngine#wrap(..) we may return NEED_UNWRAP because there is no data pending in the SSL buffers. However during a handshake if the SSL buffers were just drained, and filled up the destination buffer it is possible OpenSSL may produce more data on the next call to SSL_write. This means we should keep trying to call SSL_write as long as the destination buffer is filled and only return NEED_UNWRAP when the destination buffer is not full and there is no data pending in OpenSSL's buffers.

Modifications:
- If the handshake produces data in OpenSslEngine#wrap(..) we should return NEED_WRAP if the destination buffer is completely filled

Result:
OpenSslEngine returns the correct handshake status from wrap().
Fixes #6796.
@Scottmitch
Copy link
Member

@rkapsi - Please re-open if PR #6803 didn't completely solve the issue.

liuzhengyang pushed a commit to liuzhengyang/netty that referenced this issue Sep 10, 2017
Motivation:
If the destination buffer is completely filled during a call to OpenSslEngine#wrap(..) we may return NEED_UNWRAP because there is no data pending in the SSL buffers. However during a handshake if the SSL buffers were just drained, and filled up the destination buffer it is possible OpenSSL may produce more data on the next call to SSL_write. This means we should keep trying to call SSL_write as long as the destination buffer is filled and only return NEED_UNWRAP when the destination buffer is not full and there is no data pending in OpenSSL's buffers.

Modifications:
- If the handshake produces data in OpenSslEngine#wrap(..) we should return NEED_WRAP if the destination buffer is completely filled

Result:
OpenSslEngine returns the correct handshake status from wrap().
Fixes netty#6796.
kiril-me pushed a commit to kiril-me/netty that referenced this issue Feb 28, 2018
Motivation:
If the destination buffer is completely filled during a call to OpenSslEngine#wrap(..) we may return NEED_UNWRAP because there is no data pending in the SSL buffers. However during a handshake if the SSL buffers were just drained, and filled up the destination buffer it is possible OpenSSL may produce more data on the next call to SSL_write. This means we should keep trying to call SSL_write as long as the destination buffer is filled and only return NEED_UNWRAP when the destination buffer is not full and there is no data pending in OpenSSL's buffers.

Modifications:
- If the handshake produces data in OpenSslEngine#wrap(..) we should return NEED_WRAP if the destination buffer is completely filled

Result:
OpenSslEngine returns the correct handshake status from wrap().
Fixes netty#6796.
pulllock pushed a commit to pulllock/netty that referenced this issue Oct 19, 2023
Motivation:
If the destination buffer is completely filled during a call to OpenSslEngine#wrap(..) we may return NEED_UNWRAP because there is no data pending in the SSL buffers. However during a handshake if the SSL buffers were just drained, and filled up the destination buffer it is possible OpenSSL may produce more data on the next call to SSL_write. This means we should keep trying to call SSL_write as long as the destination buffer is filled and only return NEED_UNWRAP when the destination buffer is not full and there is no data pending in OpenSSL's buffers.

Modifications:
- If the handshake produces data in OpenSslEngine#wrap(..) we should return NEED_WRAP if the destination buffer is completely filled

Result:
OpenSslEngine returns the correct handshake status from wrap().
Fixes netty#6796.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

5 participants