mina-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Andrew C (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (DIRMINA-937) sslfilter hangs with openjdk works with oracle?
Date Tue, 05 Mar 2013 18:22:14 GMT

    [ https://issues.apache.org/jira/browse/DIRMINA-937?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13593709#comment-13593709
] 

Andrew C commented on DIRMINA-937:
----------------------------------

> Couldn't it be a problem with the cipher suite you use ?

Perhaps - for instance, bouncy castle isn't in the class path - and it was an early suspect.
 However, the only thing I change to get it working is the JVM - class paths are identical.

The OpenJDK 6 could do with an update, which I'll try once I've spun up a new test VM.

> However, in any case, it should not hang. Can you share the code that you use so that
I can debug the code using OpenJDK ? (just the initialization part, it should be enough)

This is the relevant part:

    private NioSocketAcceptor createNewAcceptor(InetSocketAddress address, KeyStoreProxy keyStoreProxy)
throws Exception {
        NioSocketAcceptor acceptor = new DefaultForwardingAcceptorFactory().createNioSocketAcceptor(null);
        logger.info("Network interface {}", address);
        acceptor.setDefaultLocalAddress(address);
        if (keyStoreProxy == null) {
            logger.info("SSL Disabled");
        } else {
            logger.info("SSL enabled using key store {}", keyStoreProxy);
            KeyStore keyStore = keyStoreProxy.loadKeyStore();
            SslContextFactory sslContextFactory = new SslContextFactory();
            sslContextFactory.setKeyManagerFactoryKeyStore(keyStore);
            sslContextFactory.setKeyManagerFactoryKeyStorePassword(keyStoreProxy.getPassword());
            acceptor.getFilterChain().addLast("SslFilter", new SslFilter(sslContextFactory.newInstance()));
            acceptor.getFilterChain().addLast("logger", new LoggingFilter());
        }
        logger.info("Installing network session adaptor");
        acceptor.setHandler(new NetworkServerSessionAdapter(this));
        return acceptor;
    }

Hmm, however, I wonder....

Tweaking examples.echoserver.Main to use a spare port and turn on ssl I can reproduce the
behaviour using just mina:

$ ls -1 lib
annotations-api-6.0.35.jar
catalina-6.0.35.jar
commons-lang-2.6.jar
coyote-6.0.35.jar
javassist-3.11.0.GA.jar
javassist-3.7.ga.jar
jcl-over-slf4j-1.6.6.jar
juli-6.0.35.jar
ognl-3.0.5.jar
servlet-api-6.0.35.jar
slf4j-api-1.7.2.jar
slf4j-api-1.7.2-javadoc.jar
slf4j-api-1.7.2-sources.jar
slf4j-simple-1.7.2.jar
slf4j-simple-1.7.2-javadoc.jar
slf4j-simple-1.7.2-sources.jar
spring-2.5.6.SEC03.jar
sshd-core-0.9.0-SNAPSHOT.jar

$ java -version
java version "1.6.0_27"
OpenJDK Runtime Environment (IcedTea6 1.12.1) (6b27-1.12.1-2ubuntu0.12.04.2)
OpenJDK 64-Bit Server VM (build 20.0-b12, mixed mode)

curl looks like:

$ curl --trace - -k https://127.0.0.1:4321
== Info: About to connect() to 127.0.0.1 port 4321 (#0)
== Info:   Trying 127.0.0.1... == Info: connected
== Info: successfully set certificate verify locations:
== Info:   CAfile: none
  CApath: /etc/ssl/certs
== Info: SSLv3, TLS handshake, Client hello (1):
=> Send SSL data, 217 bytes (0xd9)
0000: 01 00 00 d5 03 02 51 36 34 e6 ac 2e e2 35 72 e1 ......Q64....5r.
0010: 38 55 04 af 05 40 00 87 8e 47 e7 80 87 d4 d1 a6 8U...@...G......
0020: 43 82 2f e4 c7 3e 00 00 66 c0 14 c0 0a c0 22 c0 C./..>..f.....".
0030: 21 00 39 00 38 00 88 00 87 c0 0f c0 05 00 35 00 !.9.8.........5.
0040: 84 c0 12 c0 08 c0 1c c0 1b 00 16 00 13 c0 0d c0 ................
0050: 03 00 0a c0 13 c0 09 c0 1f c0 1e 00 33 00 32 00 ............3.2.
0060: 9a 00 99 00 45 00 44 c0 0e c0 04 00 2f 00 96 00 ....E.D...../...
0070: 41 c0 11 c0 07 c0 0c c0 02 00 05 00 04 00 15 00 A...............
0080: 12 00 09 00 14 00 11 00 08 00 06 00 03 00 ff 02 ................
0090: 01 00 00 45 00 0b 00 04 03 00 01 02 00 0a 00 34 ...E...........4
00a0: 00 32 00 0e 00 0d 00 19 00 0b 00 0c 00 18 00 09 .2..............
00b0: 00 0a 00 16 00 17 00 08 00 06 00 07 00 14 00 15 ................
00c0: 00 04 00 05 00 12 00 13 00 01 00 02 00 03 00 0f ................
00d0: 00 10 00 11 00 0f 00 01 01                      .........
[hung - should get server hello]

and the echo server looks like:

$ java -Djavax.net.debug=all -Dorg.slf4j.simpleLogger.defaultLogLevel=trace -cp lib/*:mina-example/target/classes:mina-core/target/classes
org.apache.mina.example.echoserver.Main
***
found key for : bogus
chain [0] = [
[
  Version: V1
  Subject: CN=bogus.com, OU=XXX CA, O=Bogus Inc, L=Stockholm, ST=Stockholm, C=SE
  Signature Algorithm: MD5withRSA, OID = 1.2.840.113549.1.1.4

  Key:  Sun RSA public key, 511 bits
  modulus: 4716266305158955097619267184819536762192336460125269747936292391072221240753144246603767639670387155212663695306712305083753837008428026689179662428434397
  public exponent: 65537
  Validity: [From: Mon Mar 07 10:16:35 EST 2005,
               To: Thu Mar 05 10:16:35 EST 2015]
  Issuer: CN=bogus.com, OU=XXX CA, O=Bogus Inc, L=Stockholm, ST=Stockholm, C=SE
  SerialNumber: [    422c7053]

]
  Algorithm: [MD5withRSA]
  Signature:
0000: 49 40 0E D4 06 42 85 18   B5 B3 61 9B EC 3F 3E B3  I@...B....a..?>.
0010: C2 D4 32 6E 28 DD F6 A2   85 39 4F A7 64 6D 10 BA  ..2n(....9O.dm..
0020: 03 1C 88 B4 D4 69 4A 45   09 35 A9 17 E8 A4 CC E1  .....iJE.5......
0030: 13 0B 40 17 79 20 F4 7C   0F 5B 92 95 A5 3A 6B 23  ..@.y ...[...:k#

]
***
trigger seeding of SecureRandom
done seeding SecureRandom
SSL ON
Listening on port 4321
R: 0.0, W: 0.0
R: 0.0, W: 0.0
[NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslFilter - Adding the SSL Filter sslFilter
to the chain
[NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler - Session Server[1](no sslEngine)
Initializing the SSL Handler
Using SSLEngineImpl.
Allow unsafe renegotiation: false
Allow legacy hello messages: true
Is initial handshake: true
Is secure renegotiation: false
[NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler - Session Server[1](no sslEngine)
SSL Handler Initialization done.
[NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslFilter - Session Server[1](ssl...) :
Starting the first handshake
[NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler - Session Server[1](ssl...) processing
the NEED_UNWRAP state
[NioProcessor-2] INFO org.apache.mina.example.echoserver.EchoProtocolHandler - OPENED
[NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslFilter - Session Server[1](ssl...): Message
received : HeapBuffer[pos=0 lim=222 cap=2048: 16 03 01 00 D9 01 00 00 D5 03 02 51 36 35 B6
40...]
[NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler - Session Server[1](ssl...) Processing
the received message
[NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler - Session Server[1](ssl...) processing
the NEED_UNWRAP state
[Raw read]: length = 5
0000: 16 03 01 00 D9                                     .....
[Raw read]: length = 217
0000: 01 00 00 D5 03 02 51 36   35 B6 40 C7 E2 FF 32 79  ......Q65.@...2y
0010: 0E 99 7E B0 9F F3 70 66   E9 B2 07 75 D1 E0 7D CC  ......pf...u....
0020: 2D F7 82 45 A3 56 00 00   66 C0 14 C0 0A C0 22 C0  -..E.V..f.....".
0030: 21 00 39 00 38 00 88 00   87 C0 0F C0 05 00 35 00  !.9.8.........5.
0040: 84 C0 12 C0 08 C0 1C C0   1B 00 16 00 13 C0 0D C0  ................
0050: 03 00 0A C0 13 C0 09 C0   1F C0 1E 00 33 00 32 00  ............3.2.
0060: 9A 00 99 00 45 00 44 C0   0E C0 04 00 2F 00 96 00  ....E.D...../...
0070: 41 C0 11 C0 07 C0 0C C0   02 00 05 00 04 00 15 00  A...............
0080: 12 00 09 00 14 00 11 00   08 00 06 00 03 00 FF 02  ................
0090: 01 00 00 45 00 0B 00 04   03 00 01 02 00 0A 00 34  ...E...........4
00A0: 00 32 00 0E 00 0D 00 19   00 0B 00 0C 00 18 00 09  .2..............
00B0: 00 0A 00 16 00 17 00 08   00 06 00 07 00 14 00 15  ................
00C0: 00 04 00 05 00 12 00 13   00 01 00 02 00 03 00 0F  ................
00D0: 00 10 00 11 00 0F 00 01   01                       .........
NioProcessor-2, READ: TLSv1 Handshake, length = 217
[NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler - Session Server[1](ssl...) processing
the NEED_TASK state
*** ClientHello, TLSv1.1
RandomCookie:  GMT: 1362506934 bytes = { 64, 199, 226, 255, 50, 121, 14, 153, 126, 176, 159,
243, 112, 102, 233, 178, 7, 117, 209, 224, 125, 204, 45, 247, 130, 69, 163, 86 }
Session ID:  {}
Cipher Suites: [TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA,
Unknown 0xc0:0x22, Unknown 0xc0:0x21, TLS_DHE_RSA_WITH_AES_256_CBC_SHA, TLS_DHE_DSS_WITH_AES_256_CBC_SHA,
Unknown 0x0:0x88, Unknown 0x0:0x87, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA,
TLS_RSA_WITH_AES_256_CBC_SHA, Unknown 0x0:0x84, TLS_ECDHE_RSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDHE_ECDSA_WITH_3DES_EDE_CBC_SHA,
Unknown 0xc0:0x1c, Unknown 0xc0:0x1b, SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_DSS_WITH_3DES_EDE_CBC_SHA,
TLS_ECDH_RSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDH_ECDSA_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_3DES_EDE_CBC_SHA,
TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, Unknown 0xc0:0x1f,
Unknown 0xc0:0x1e, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, Unknown
0x0:0x9a, Unknown 0x0:0x99, Unknown 0x0:0x45, Unknown 0x0:0x44, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA,
TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_128_CBC_SHA, Unknown 0x0:0x96, Unknown
0x0:0x41, TLS_ECDHE_RSA_WITH_RC4_128_SHA, TLS_ECDHE_ECDSA_WITH_RC4_128_SHA, TLS_ECDH_RSA_WITH_RC4_128_SHA,
TLS_ECDH_ECDSA_WITH_RC4_128_SHA, SSL_RSA_WITH_RC4_128_SHA, SSL_RSA_WITH_RC4_128_MD5, SSL_DHE_RSA_WITH_DES_CBC_SHA,
SSL_DHE_DSS_WITH_DES_CBC_SHA, SSL_RSA_WITH_DES_CBC_SHA, SSL_DHE_RSA_EXPORT_WITH_DES40_CBC_SHA,
SSL_DHE_DSS_EXPORT_WITH_DES40_CBC_SHA, SSL_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_RSA_EXPORT_WITH_RC2_CBC_40_MD5,
SSL_RSA_EXPORT_WITH_RC4_40_MD5, TLS_EMPTY_RENEGOTIATION_INFO_SCSV]
Compression Methods:  { 1, 0 }
Extension ec_point_formats, formats: [uncompressed, ansiX962_compressed_prime, ansiX962_compressed_char2]
Extension elliptic_curves, curve names: {sect571r1, sect571k1, secp521r1, sect409k1, sect409r1,
secp384r1, sect283k1, sect283r1, secp256k1, secp256r1, sect239k1, sect233k1, sect233r1, secp224k1,
secp224r1, sect193r1, sect193r2, secp192k1, secp192r1, sect163k1, sect163r1, sect163r2, secp160k1,
secp160r1, secp160r2}
Unsupported extension type_15, data: 01
***
[read] MD5 and SHA1 hashes:  len = 217
0000: 01 00 00 D5 03 02 51 36   35 B6 40 C7 E2 FF 32 79  ......Q65.@...2y
0010: 0E 99 7E B0 9F F3 70 66   E9 B2 07 75 D1 E0 7D CC  ......pf...u....
0020: 2D F7 82 45 A3 56 00 00   66 C0 14 C0 0A C0 22 C0  -..E.V..f.....".
0030: 21 00 39 00 38 00 88 00   87 C0 0F C0 05 00 35 00  !.9.8.........5.
0040: 84 C0 12 C0 08 C0 1C C0   1B 00 16 00 13 C0 0D C0  ................
0050: 03 00 0A C0 13 C0 09 C0   1F C0 1E 00 33 00 32 00  ............3.2.
0060: 9A 00 99 00 45 00 44 C0   0E C0 04 00 2F 00 96 00  ....E.D...../...
0070: 41 C0 11 C0 07 C0 0C C0   02 00 05 00 04 00 15 00  A...............
0080: 12 00 09 00 14 00 11 00   08 00 06 00 03 00 FF 02  ................
0090: 01 00 00 45 00 0B 00 04   03 00 01 02 00 0A 00 34  ...E...........4
00A0: 00 32 00 0E 00 0D 00 19   00 0B 00 0C 00 18 00 09  .2..............
00B0: 00 0A 00 16 00 17 00 08   00 06 00 07 00 14 00 15  ................
00C0: 00 04 00 05 00 12 00 13   00 01 00 02 00 03 00 0F  ................
00D0: 00 10 00 11 00 0F 00 01   01                       .........
matching alias: bogus
[NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslHandler - Session Server[1](ssl...) processing
the NEED_UNWRAP state
[NioProcessor-2] DEBUG org.apache.mina.filter.ssl.SslFilter - Session Server[1](ssl...): Processing
the SSL Data
R: 0.0, W: 0.0
R: 0.0, W: 0.0
R: 0.0, W: 0.0
R: 0.0, W: 0.0
[NioProcessor-2] INFO org.apache.mina.example.echoserver.EchoProtocolHandler - *** IDLE #1
***
R: 0.0, W: 0.0
R: 0.0, W: 0.0
R: 0.0, W: 0.0
[NioProcessor-2] INFO org.apache.mina.example.echoserver.EchoProtocolHandler - *** IDLE #2
***

and, again, switching to oracle's jvm and it works.
                
> sslfilter hangs with openjdk works with oracle?
> -----------------------------------------------
>
>                 Key: DIRMINA-937
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-937
>             Project: MINA
>          Issue Type: Bug
>          Components: Filter
>    Affects Versions: 2.0.7
>         Environment: OpenJDK Runtime Environment (IcedTea6 1.12.1) (6b27-1.12.1-2ubuntu0.12.04.2)
> OpenJDK 64-Bit Server VM (build 20.0-b12, mixed mode)
>            Reporter: Andrew C
>
> Still gathering information, however ...
> I've a server that's using SslFilter.  When I test a connection using curl (two different
versions; curl -k --trace - https://localhost:4321) it hangs:
> - curl sends the client hello
> - never gets any response
> looking at an extract of the logs I see:
> [read] MD5 and SHA1 hashes:  len = 235
> 0000: 01 00 00 E7 03 02 51 35   14 CC 56 9F 1B 4E B0 80  ......Q5..V..N..
> ...
> 00E0: 00 0F 00 10 00 11 00 0F   00 01 01                 ...........
> matching alias: mykey
> [2013-03-04=16:40:28.836] [NioProcessor-1] DEBUG org.apache.mina.filter.ssl.SslHandler
- Session Server[2](ssl...) processing the NEED_UNWRAP state
> [2013-03-04=16:40:28.836] [NioProcessor-1] DEBUG org.apache.mina.filter.ssl.SslFilter
- Session Server[2](ssl...): Processing the SSL Data
> i.e., SSLEngine's indicated that it is expecting more data from curl.
> If I switch to oracle's jvm, things work - that is the NEED_UNWRAP doesn't appear and
SSLEngine starts sending data back to the curl client:
> ...
> 00E0: 00 0F 00 10 00 11 00 0F   00 01 01                 ...........
> matching alias: mykey
> %% Created:  [Session-1, SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA]
> *** ServerHello, TLSv1
> ...
> any one else seen this?

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

Mime
View raw message