[OPENDJ-4920] LDAPS connections which are still inside handshake do not get idle closed Created: 23/Mar/18  Updated: 08/Nov/19

Status: Dev backlog
Project: OpenDJ
Component/s: core apis, core server
Affects Version/s: 6.0.0, 5.5.0, 4.0.0, 3.5.0
Fix Version/s: None

Type: Bug Priority: Major
Reporter: Lee Trujillo Assignee: Yannick Lecaillez
Resolution: Unresolved Votes: 0
Labels: release-notes

Attachments: Zip Archive SlowSSL.zip     File jstack.out    
Support Ticket IDs:

 Description   

A client connection gets stuck completing its TLS handshake and as a result, cannot be disconnected by the Idle Time Limit thread and a deadlock ensues.

 

 

Found one Java-level deadlock:
=============================
"Idle Time Limit Thread":
waiting to lock monitor 0x0000000000a38940 (object 0x00000000b10329a8, a java.lang.Object),
which is held by "LDAP Request Handler 3 for connection handler LDAPS Connection Handler 0.0.0.0 port 636"
"LDAP Request Handler 3 for connection handler LDAPS Connection Handler 0.0.0.0 port 636":
waiting to lock monitor 0x000000000094fea0 (object 0x00000000b10329b8, a java.lang.Object),
which is held by "Idle Time Limit Thread"

Java stack information for the threads listed above:
===================================================
"Idle Time Limit Thread":
at org.opends.server.extensions.TLSByteChannel$ByteChannelImpl.doRecvAndUnwrap(TLSByteChannel.java:218)
- waiting to lock <0x00000000b10329a8> (a java.lang.Object)
at org.opends.server.extensions.TLSByteChannel$ByteChannelImpl.doHandshake(TLSByteChannel.java:199)
- locked <0x00000000b10329b8> (a java.lang.Object)
at org.opends.server.extensions.TLSByteChannel$ByteChannelImpl.write(TLSByteChannel.java:152)
- locked <0x00000000b10329c8> (a java.lang.Object)
at org.opends.server.extensions.RedirectingByteChannel.write(RedirectingByteChannel.java:117)
at org.opends.server.extensions.RedirectingByteChannel.write(RedirectingByteChannel.java:121)
at org.forgerock.opendj.ldap.ByteStringBuilder.copyTo(ByteStringBuilder.java:919)
at org.opends.server.protocols.ldap.LDAPClientConnection.sendLDAPMessage(LDAPClientConnection.java:923)
at org.opends.server.protocols.ldap.LDAPClientConnection.disconnect(LDAPClientConnection.java:1041)
at org.opends.server.core.IdleTimeLimitThread.run(IdleTimeLimitThread.java:113)
"LDAP Request Handler 3 for connection handler LDAPS Connection Handler 0.0.0.0 port 636":
at org.opends.server.extensions.TLSByteChannel$ByteChannelImpl.doHandshake(TLSByteChannel.java:177)
- waiting to lock <0x00000000b10329b8> (a java.lang.Object)
at org.opends.server.extensions.TLSByteChannel$ByteChannelImpl.doRecvAndUnwrap(TLSByteChannel.java:293)
- locked <0x00000000b10329a8> (a java.lang.Object)
at org.opends.server.extensions.TLSByteChannel$ByteChannelImpl.read(TLSByteChannel.java:105)
- locked <0x00000000b1032a98> (a java.lang.Object)
at org.opends.server.extensions.RedirectingByteChannel.read(RedirectingByteChannel.java:91)
at org.opends.server.extensions.RedirectingByteChannel.read(RedirectingByteChannel.java:95)
at org.opends.server.protocols.ldap.ASN1ByteChannelReader.processChannelData(ASN1ByteChannelReader.java:323)
at org.opends.server.protocols.ldap.LDAPClientConnection.processDataRead(LDAPClientConnection.java:1454)
at org.opends.server.protocols.ldap.LDAPRequestHandler.run(LDAPRequestHandler.java:277)

 

 

"Idle Time Limit Thread" daemon prio=3 tid=0x000000000317e000 nid=0xbb waiting for monitor entry [0xffff80ffac368000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.opends.server.extensions.TLSByteChannel$ByteChannelImpl.doRecvAndUnwrap(TLSByteChannel.java:218)
- waiting to lock <0x00000000b10329a8> (a java.lang.Object)
at org.opends.server.extensions.TLSByteChannel$ByteChannelImpl.doHandshake(TLSByteChannel.java:199)
- locked <0x00000000b10329b8> (a java.lang.Object)
at org.opends.server.extensions.TLSByteChannel$ByteChannelImpl.write(TLSByteChannel.java:152)
- locked <0x00000000b10329c8> (a java.lang.Object)
at org.opends.server.extensions.RedirectingByteChannel.write(RedirectingByteChannel.java:117)
at org.opends.server.extensions.RedirectingByteChannel.write(RedirectingByteChannel.java:121)
at org.forgerock.opendj.ldap.ByteStringBuilder.copyTo(ByteStringBuilder.java:919)
at org.opends.server.protocols.ldap.LDAPClientConnection.sendLDAPMessage(LDAPClientConnection.java:923)
at org.opends.server.protocols.ldap.LDAPClientConnection.disconnect(LDAPClientConnection.java:1041)
at org.opends.server.core.IdleTimeLimitThread.run(IdleTimeLimitThread.java:113)

Locked ownable synchronizers:
- None

 

 

"LDAP Request Handler 3 for connection handler LDAPS Connection Handler 0.0.0.0 port 636" prio=3 tid=0x0000000001985000 nid=0x33 waiting for monitor entry [0xffff80ffb8106000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.opends.server.extensions.TLSByteChannel$ByteChannelImpl.doHandshake(TLSByteChannel.java:177)
- waiting to lock <0x00000000b10329b8> (a java.lang.Object)
at org.opends.server.extensions.TLSByteChannel$ByteChannelImpl.doRecvAndUnwrap(TLSByteChannel.java:293)
- locked <0x00000000b10329a8> (a java.lang.Object)
at org.opends.server.extensions.TLSByteChannel$ByteChannelImpl.read(TLSByteChannel.java:105)
- locked <0x00000000b1032a98> (a java.lang.Object)
at org.opends.server.extensions.RedirectingByteChannel.read(RedirectingByteChannel.java:91)
at org.opends.server.extensions.RedirectingByteChannel.read(RedirectingByteChannel.java:95)
at org.opends.server.protocols.ldap.ASN1ByteChannelReader.processChannelData(ASN1ByteChannelReader.java:323)
at org.opends.server.protocols.ldap.LDAPClientConnection.processDataRead(LDAPClientConnection.java:1454)
at org.opends.server.protocols.ldap.LDAPRequestHandler.run(LDAPRequestHandler.java:277)

Locked ownable synchronizers:
- None

JVM

java version "1.7.0_51" 
Java(TM) SE Runtime Environment (build 1.7.0_51-b13) 
Java HotSpot(TM) 64-Bit Server VM (build 24.51-b03, mixed mode)

 The Idle Timeout was set between 2 minutes and 50000 ms. No setting had an effect on the problem.

 



 Comments   
Comment by Ludovic Poitou [ 23/Mar/18 ]

I'm a little bit confused, but how long did the connection got stuck in the TSL Handshake ?

 

Comment by Chris Ridd [ 06/Apr/18 ]

I've added a sample "bad client", based on the code at this Github project.

java -jar target/SlowSSL-1.0-SNAPSHOT-jar-with-dependencies.jar localhost 1636 100000

The last argument is the number of ms to sleep at each stage of the handshake. Make it much bigger than DS's global idle-time-limit to make it easier to observe the problems. In 6.x there's no deadlock, but the connection still does not get idle closed.

Comment by Lee Trujillo [ 06/Apr/18 ]

Ludovic Poitou

 

Note, I added the following to the main notes after you asked.

 The Idle Timeout was set between 2 minutes and 50000 ms. No setting had an effect on the problem.

Comment by Ludovic Poitou [ 06/Apr/18 ]

Idle Timeout is a function on established connections.
When connecting to the LDAPS port, the connection is not established at LDAP level until the SSL layer is fully established.
The issue lies in some internal timeout in the SSL layer which is Java code, not really ours.

Generated at Sun Jun 07 06:43:00 UTC 2020 using Jira 7.13.12#713012-sha1:6e07c38070d5191bbf7353952ed38f111754533a.