Connection manager issue (SSL problem)

Hello all,

Here is my design :

INTERNET: Spark client --> DMZ : Connection manager --> LAN: Openfire Server

Openfire version 4.0.2 (running en débian 8.4)

Connection manager version 3.6.3 (running on debian 8.4)

Port 5222 and 5223 are open between INTERNET and DMZ

Port 5262 and 53 are open between DMZ and LAN (I also opened 5222 and 5223 but not sure that this is a requirement).

All above ports have been test trough telnet and work fine.

nslookup from my connection manager with the name of my openfire server works fine and I get the full name (with the dns sub (domain.com)).

When I start connection manager on my connection manager server, it contact the openfire server but the openfire server doesn’t register the connection manager server.

Apparently the connection is closed before receiving peer’s close notification.

Here is the log from the openfire side :

*2016.05.30 11:18:08 org.apache.mina.core.filterchain.IoFilterEvent - Firing a SESSION_OPENED event for session 7 *

*2016.05.30 11:18:08 org.apache.mina.core.filterchain.IoFilterEvent - Event SESSION_OPENED has been fired for session 7 *

*2016.05.30 11:18:08 org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_RECEIVED to session 7 *

*Queue : [MESSAGE_RECEIVED, ] *

*2016.05.30 11:18:08 org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_RECEIVED event for session 7 *

*2016.05.30 11:18:08 org.apache.mina.filter.codec.ProtocolCodecFilter - Processing a MESSAGE_RECEIVED for session 7 *

*2016.05.30 11:18:08 org.jivesoftware.openfire.session.LocalConnectionMultiplexerSession - LocalConnectionMultiplexerSession: [ConMng] Starting registration of new connection manager for domain: 35cb7/Connection Worker - 1 *

*2016.05.30 11:18:08 org.jivesoftware.openfire.session.LocalConnectionMultiplexerSession - LocalConnectionMultiplexerSession: [ConMng] Send stream header with ID: 4hd4z6fyh6 for connection manager with domain: 35cb7/Connection Worker - 1 *

*2016.05.30 11:18:08 org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_RECEIVED has been fired for session 7 *

*2016.05.30 11:18:08 org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_SENT to session 7 *

*Queue : [MESSAGE_SENT, ] *

*2016.05.30 11:18:08 org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_SENT to session 7 *

*Queue : [MESSAGE_SENT, , MESSAGE_SENT, ] *

*2016.05.30 11:18:08 org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_SENT event for session 7 *

*2016.05.30 11:18:08 org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_SENT has been fired for session 7 *

*2016.05.30 11:18:08 org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_SENT event for session 7 *

*2016.05.30 11:18:08 org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_SENT has been fired for session 7 *

*2016.05.30 11:18:08 org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event MESSAGE_RECEIVED to session 7 *

*Queue : [MESSAGE_RECEIVED, ] *

*2016.05.30 11:18:08 org.apache.mina.core.filterchain.IoFilterEvent - Firing a MESSAGE_RECEIVED event for session 7 *

*2016.05.30 11:18:08 org.apache.mina.filter.codec.ProtocolCodecFilter - Processing a MESSAGE_RECEIVED for session 7 *

*2016.05.30 11:18:08 org.jivesoftware.openfire.keystore.OpenfireX509TrustManager - Constructed trust manager. Number of trusted issuers: 163, accepts self-signed: false, checks validity: false *

*2016.05.30 11:18:08 org.jivesoftware.openfire.keystore.OpenfireX509TrustManager - Constructed trust manager. Number of trusted issuers: 163, accepts self-signed: false, checks validity: false *

*2016.05.30 11:18:08 org.apache.mina.filter.ssl.SslFilter - Adding the SSL Filter tls to the chain *

*2016.05.30 11:18:08 org.apache.mina.filter.ssl.SslHandler - Session Server[7](no sslEngine) Initializing the SSL Handler *

*2016.05.30 11:18:08 org.apache.mina.filter.ssl.SslHandler - Session Server[7](no sslEngine) SSL Handler Initialization done. *

*2016.05.30 11:18:08 org.apache.mina.filter.ssl.SslFilter - Session Server7 : Starting the first handshake *

*2016.05.30 11:18:08 org.apache.mina.filter.ssl.SslHandler - Session Server7 processing the NEED_UNWRAP state *

*2016.05.30 11:18:08 org.apache.mina.filter.ssl.SslFilter - Session Server7: Writing Message : WriteRequest: HeapBuffer[pos=0 lim=50 cap=64: 3C 70 72 6F 63 65 65 64 20 78 6D 6C 6E 73 3D 22…] *

*2016.05.30 11:18:08 org.apache.mina.core.filterchain.IoFilterEvent - Event MESSAGE_RECEIVED has been fired for session 7 *

*2016.05.30 11:18:08 org.apache.mina.filter.ssl.SslFilter - Session Server7: Message received : HeapBuffer[pos=0 lim=112 cap=1024: 16 03 01 00 6B 01 00 00 67 03 01 57 4C 05 50 09…] *

*2016.05.30 11:18:08 org.apache.mina.filter.ssl.SslHandler - Session Server7 Processing the received message *

*2016.05.30 11:18:08 org.apache.mina.filter.ssl.SslHandler - Session Server7 processing the NEED_UNWRAP state *

*2016.05.30 11:18:08 org.apache.mina.filter.ssl.SslHandler - Session Server7 processing the NEED_TASK state *

*2016.05.30 11:18:08 org.apache.mina.filter.ssl.SslHandler - Session Server7 processing the NEED_WRAP state *

*2016.05.30 11:18:08 org.apache.mina.filter.ssl.SslFilter - Session Server7: Writing Message : WriteRequest: HeapBuffer[pos=0 lim=1210 cap=2115: 16 03 01 04 B5 02 00 00 4D 03 01 57 4C 05 50 B1…] *

*2016.05.30 11:18:08 org.apache.mina.filter.ssl.SslHandler - Session Server7 processing the NEED_UNWRAP state *

*2016.05.30 11:18:08 org.apache.mina.filter.ssl.SslFilter - Session Server7: Processing the SSL Data *

*2016.05.30 11:18:09 org.apache.mina.filter.ssl.SslFilter - Session Server7: Message received : HeapBuffer[pos=0 lim=16 cap=1024: 3C 2F 73 74 72 65 61 6D 3A 73 74 72 65 61 6D 3E] *

*2016.05.30 11:18:09 org.apache.mina.filter.ssl.SslHandler - Session Server7 Processing the received message *

*2016.05.30 11:18:09 org.apache.mina.filter.ssl.SslHandler - Session Server7 processing the NEED_UNWRAP state *

*2016.05.30 11:18:09 org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event EXCEPTION_CAUGHT to session 7 *

*Queue : [EXCEPTION_CAUGHT, ] *

*2016.05.30 11:18:09 org.apache.mina.core.filterchain.IoFilterEvent - Firing a EXCEPTION_CAUGHT event for session 7 *

*2016.05.30 11:18:09 org.apache.mina.filter.ssl.SslFilter - Session Server7: Writing Message : WriteRequest: HeapBuffer[pos=0 lim=145 cap=256: 3C 73 74 72 65 61 6D 3A 65 72 72 6F 72 20 78 6D…] *

*2016.05.30 11:18:09 org.apache.mina.filter.ssl.SslFilter - Session Server[7]: Writing Message : WriteRequest: HeapBuffer[pos=0 lim=7 cap=8: 15 03 01 00 02 02 50] *

*2016.05.30 11:18:09 org.apache.mina.filter.ssl.SslHandler - Unexpected exception from SSLEngine.closeInbound(). *

*javax.net.ssl.SSLException: Inbound closed before receiving peer’s close_notify: possible truncation attack? *

*at sun.security.ssl.Alerts.getSSLException(Alerts.java:208) *

*at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1650) *

*at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1618) *

*at sun.security.ssl.SSLEngineImpl.closeInbound(SSLEngineImpl.java:1548) *

*at org.apache.mina.filter.ssl.SslHandler.destroy(SslHandler.java:204) *

*at org.apache.mina.filter.ssl.SslFilter.initiateClosure(SslFilter.java:672) *

*at org.apache.mina.filter.ssl.SslFilter.filterClose(SslFilter.java:627) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterClose(D efaultIoFilterChain.java:498) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilt erChain.java:47) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterClose(D efaultIoFilterChain.java:780) *

*at org.apache.mina.filter.executor.ExecutorFilter.filterClose(ExecutorFilter.java: 627) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterClose(D efaultIoFilterChain.java:498) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilt erChain.java:47) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterClose(D efaultIoFilterChain.java:780) *

*at org.apache.mina.core.filterchain.IoFilterAdapter.filterClose(IoFilterAdapter.ja va:130) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterClose(D efaultIoFilterChain.java:498) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilt erChain.java:47) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterClose(D efaultIoFilterChain.java:780) *

*at org.apache.mina.core.filterchain.IoFilterAdapter.filterClose(IoFilterAdapter.ja va:130) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterClose(D efaultIoFilterChain.java:498) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1500(DefaultIoFilt erChain.java:47) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.filterClose(D efaultIoFilterChain.java:780) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.filterClose(De faultIoFilterChain.java:710) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain.callPreviousFilterClose(D efaultIoFilterChain.java:498) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain.fireFilterClose(DefaultIo FilterChain.java:491) *

*at org.apache.mina.core.session.AbstractIoSession.close(AbstractIoSession.java:310 ) *

*at org.apache.mina.core.session.AbstractIoSession.close(AbstractIoSession.java:289 ) *

*at org.jivesoftware.openfire.nio.NIOConnection.close(NIOConnection.java:244) *

*at org.jivesoftware.openfire.nio.ConnectionHandler.exceptionCaught(ConnectionHandl er.java:162) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.exceptionCaugh t(DefaultIoFilterChain.java:672) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextExceptionCaught(D efaultIoFilterChain.java:461) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1100(DefaultIoFilt erChain.java:47) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.exceptionCaug ht(DefaultIoFilterChain.java:760) *

*at org.apache.mina.core.filterchain.IoFilterAdapter.exceptionCaught(IoFilterAdapte r.java:102) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextExceptionCaught(D efaultIoFilterChain.java:461) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1100(DefaultIoFilt erChain.java:47) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.exceptionCaug ht(DefaultIoFilterChain.java:760) *

*at org.apache.mina.core.filterchain.IoFilterAdapter.exceptionCaught(IoFilterAdapte r.java:102) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextExceptionCaught(D efaultIoFilterChain.java:461) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1100(DefaultIoFilt erChain.java:47) *

*at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.exceptionCaug ht(DefaultIoFilterChain.java:760) *

*at org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:93) *

*at org.apache.mina.core.session.IoEvent.run(IoEvent.java:63) *

*at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTask(Ordere dThreadPoolExecutor.java:769) *

*at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTasks(Order edThreadPoolExecutor.java:761) *

*at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.run(OrderedThr eadPoolExecutor.java:703) *

*at java.lang.Thread.run(Thread.java:745) *

*2016.05.30 11:18:09 org.apache.mina.core.filterchain.IoFilterEvent - Event EXCEPTION_CAUGHT has been fired for session 7 *

*2016.05.30 11:18:09 org.apache.mina.filter.executor.OrderedThreadPoolExecutor - Adding event SESSION_CLOSED to session 7 *

*Queue : [SESSION_CLOSED, ] *

*2016.05.30 11:18:09 org.apache.mina.core.filterchain.IoFilterEvent - Firing a SESSION_CLOSED event for session 7 *

*2016.05.30 11:18:09 org.apache.mina.core.filterchain.IoFilterEvent - Event SESSION_CLOSED has been fired for session 7 *

*2016.05.30 11:18:20 org.jivesoftware.util.log.util.CommonsLogFactory - Closing statement 55cfb701 (belonging to connection 3) automatically *

Here is the corresponding log from the connection manager side :

2016.05.30 11:18:08 CM - Trying to connect to sag-im:5262(DNS lookup: sag-im:526 2)

2016.05.30 11:18:08 CM - Plain connection to sag-im:5262 successful

2016.05.30 11:18:08 CM - Indicating we want TLS to sag-im

2016.05.30 11:18:08 CM - Negotiating TLS with sag-im

2016.05.30 11:18:08 SubjectAltName of invalid type found: [

[

  • Version: V3*
  • Subject: CN=sag-im*
  • Signature Algorithm: SHA1withRSA, OID = 1.2.840.113549.1.1.5*
  • Key: Sun RSA public key, 2048 bits*
  • modulus: 219050829556692269047307326077768419784573312599384110165822568097137 0555833062181453005719894776868952285838232887814203321085457659665712619371735 5 0931092521598841741394980165138493610079789650081634705203137569481831314606912 4 8683200952622536711469618041417881271453913376765084691392194286084970784718959 4 9898656806959149612395623970333022650880658244880894516994134530876494012266245 3 7596373608765024786051480412726225696840419918964300107901141737650556838184563 9 7777982857365752810181078037843212963107642520907581620345871541133183902906357 2 89678846642670114344062936587692203045112527711307925181287580990129*
  • public exponent: 65537*
  • Validity: [From: Tue May 17 16:57:13 CEST 2016,*
  •           To: Sun May 16 16:57:13 CEST 2021]*
    
  • Issuer: CN=sag-im*
  • SerialNumber: [ 732fbbdf dd50c062]*

Certificate Extensions: 3

[1]: ObjectId: 2.5.29.35 Criticality=false

AuthorityKeyIdentifier [

KeyIdentifier [

0000: 44 76 EF 11 87 CE A5 EB 60 D1 FC 98 7E 49 23 48 Dv…`…I#H

0010: 37 44 06 8C 7D…

]

]

[2]: ObjectId: 2.5.29.17 Criticality=false

SubjectAlternativeName [

  • Other-Name: Unrecognized ObjectIdentifier: 1.3.6.1.5.5.7.8.5*

]

[3]: ObjectId: 2.5.29.14 Criticality=false

SubjectKeyIdentifier [

KeyIdentifier [

0000: 44 76 EF 11 87 CE A5 EB 60 D1 FC 98 7E 49 23 48 Dv…`…I#H

0010: 37 44 06 8C 7D…

]

]

]

  • Algorithm: [SHA1withRSA]*
  • Signature:*

0000: AA 6F 42 A6 B7 63 1E 08 BE 3D 34 BE 83 00 51 CB .oB…c…=4…Q.

0010: 64 2F 89 46 43 5C FC 00 C8 9F DF D3 69 98 D2 21 d/.FC…i…!

0020: E3 47 08 6D 1A 13 F6 7B 9F 6E 75 7C 23 A9 5B 74 .G.m…nu.#.[t

0030: 90 72 30 2C FB 1F CE 0C 01 AC 19 89 85 FE 5D C8 .r0,…].

0040: D7 69 FE C8 DB B1 D1 DF 21 B7 97 08 3C 20 B1 25 .i…!..< .%

0050: BE B7 63 09 28 93 F7 67 D3 B1 1D 1E 44 33 52 08 …c.(…g…D3R.

0060: 7C ED B7 17 32 7F B3 EE 14 3E 42 D0 96 A1 72 F5 …2…>B…r.

0070: 28 97 84 E7 4F 1C 04 A1 C2 0E C7 9F D2 22 C2 10 (…O…"…

0080: A2 AC A3 6B 8F 2A 1F B5 49 29 D3 F8 E7 CD E2 AA …k.*…I)…

0090: 1C 3B C1 51 BC 73 DF C4 4A F7 05 F7 7B F6 54 F8 .;.Q.s…J…T.

00A0: 3F C4 8C 94 74 00 60 DA CE 18 E8 34 6B 44 F5 A6 ?..t.`…4kD…

00B0: 25 23 4C 35 64 86 8F DA 60 2C ED DE D8 DC 9B A8 %#L5d…`,…

00C0: C4 3C 97 60 63 BA 3E 44 71 25 E4 6B 25 5F 03 E5 .<.`c.>Dq%.k%_…

00D0: 2D FB D4 61 7C F6 60 EB F5 16 2E 6D F3 9B D3 3B -…a…`…m…;

00E0: DB 61 51 E1 9B 0B C0 03 20 DB 0D 66 8A 1D BB FD .aQ… …f…

00F0: 29 48 B2 95 09 6A 98 A1 E3 10 21 C6 C2 49 B1 6B )H…j…!..I.k

]

Please help !

Thanks