Lucee Datasource Connection Pool Threads Locking

dev support
1

We have an application that runs about 2000 websites on a handful of VMs run by Lucee. We’ve seen a number of times now where one domain will effectively “lock up” on a lucee VM. Once the VM gets enough requests backed up, it will stop accepting new requests and need a restart. When this occurs, we observe requests have their current thread blocked by a “RUNNABLE” thread. The waiting threads are stuck trying to get a datasource connection. This leads me to believe there is something going on with the datasource connection pool where a thread is holding a lock, exhausting connections, or not releasing a connection back to the pool when its complete.

I saved off the thread stack for the blocking thread that is causing problems when this occurs. It looks like it is holding a lock on the datasource that it isn’t freeing up.

Any ideas what I can do to resolve these? It’s unfortunately becoming somewhat common.

java.net.SocketInputStream.socketRead0(Native Method)
java.net.SocketInputStream.socketRead(Unknown Source)
java.net.SocketInputStream.read(Unknown Source)
java.net.SocketInputStream.read(Unknown Source)
com.microsoft.sqlserver.jdbc.TDSChannel$ProxyInputStream.readInternal(IOBuffer.java:1193)
com.microsoft.sqlserver.jdbc.TDSChannel$ProxyInputStream.read(IOBuffer.java:1179)
com.microsoft.sqlserver.jdbc.TDSChannel$ProxyInputStream.readInternal(IOBuffer.java:1193)
com.microsoft.sqlserver.jdbc.TDSChannel$ProxyInputStream.read(IOBuffer.java:1179)
sun.security.ssl.SSLSocketInputRecord.read(Unknown Source)
sun.security.ssl.SSLSocketInputRecord.readFully(Unknown Source)
sun.security.ssl.SSLSocketInputRecord.decodeInputRecord(Unknown Source)
sun.security.ssl.SSLSocketInputRecord.decode(Unknown Source)
sun.security.ssl.SSLTransport.decode(Unknown Source)
sun.security.ssl.SSLSocketImpl.decode(Unknown Source)
sun.security.ssl.SSLSocketImpl.readApplicationRecord(Unknown Source)
sun.security.ssl.SSLSocketImpl$AppInputStream.read(Unknown Source)
com.microsoft.sqlserver.jdbc.TDSChannel$ProxyInputStream.readInternal(IOBuffer.java:1193)
com.microsoft.sqlserver.jdbc.TDSChannel$ProxyInputStream.read(IOBuffer.java:1179)
com.microsoft.sqlserver.jdbc.TDSChannel.read(IOBuffer.java:2151)
com.microsoft.sqlserver.jdbc.TDSReader.readPacket(IOBuffer.java:6840)
com.microsoft.sqlserver.jdbc.TDSReader.nextPacket(IOBuffer.java:6788)
com.microsoft.sqlserver.jdbc.TDSReader.ensurePayload(IOBuffer.java:6760)
com.microsoft.sqlserver.jdbc.TDSReader.peekTokenType(IOBuffer.java:6985)
com.microsoft.sqlserver.jdbc.TDSParser.parse(tdsparser.java:66)
com.microsoft.sqlserver.jdbc.SQLServerStatement.getNextResult(SQLServerStatement.java:1691)
com.microsoft.sqlserver.jdbc.SQLServerStatement.processResults(SQLServerStatement.java:1356)
com.microsoft.sqlserver.jdbc.SQLServerStatement.processBatch(SQLServerStatement.java:1347)
com.microsoft.sqlserver.jdbc.SQLServerStatement.processExecuteResults(SQLServerStatement.java:1339)
com.microsoft.sqlserver.jdbc.SQLServerStatement$StmtExecCmd.processResponse(SQLServerStatement.java:821)
com.microsoft.sqlserver.jdbc.TDSCommand.close(IOBuffer.java:7755)
com.microsoft.sqlserver.jdbc.SQLServerStatement.discardLastExecutionResults(SQLServerStatement.java:155)
com.microsoft.sqlserver.jdbc.SQLServerStatement.closeInternal(SQLServerStatement.java:697)
com.microsoft.sqlserver.jdbc.SQLServerStatement.$fr$close(SQLServerStatement.java:712)
com.microsoft.sqlserver.jdbc.SQLServerStatement.close(SQLServerStatement.java)
com.microsoft.sqlserver.jdbc.SQLServerConnection.isValid(SQLServerConnection.java:7065)
lucee.runtime.db.DCStack.isValidEL(DCStack.java:221)
lucee.runtime.db.DCStack.clear(DCStack.java:165)
lucee.runtime.db.DCStack.clear(DCStack.java:149)
 - locked <0x4f173a1d> (a lucee.runtime.db.DCStack)
lucee.runtime.db.DatasourceConnectionPool.clear(DatasourceConnectionPool.java:193)
lucee.runtime.engine.Controler.control(Controler.java:364)
lucee.runtime.engine.Controler.control(Controler.java:263)
lucee.runtime.engine.Controler.access$000(Controler.java:59)
lucee.runtime.engine.Controler$ControlerThread.run(Controler.java:114)
Locked ownable synchronizers: 
    - java.util.concurrent.locks.ReentrantLock$NonfairSync <0x20579367>
    - java.util.concurrent.locks.ReentrantLock$NonfairSync <0x6b725f70>
    - java.util.concurrent.locks.ReentrantLock$NonfairSync <0x1f1bd82d>
    - java.util.concurrent.locks.ReentrantLock$NonfairSync <0x2330ae55>
    - java.util.concurrent.locks.ReentrantLock$NonfairSync <0x3fe0cdff>

Don’t forget to tell us about your stack!

OS: Windows Server 2016 (10.0) 64bit
Java Version: 11.0.22 (Eclipse Adoptium) 64bit
Tomcat Version: Apache Tomcat/9.0.86
Lucee Version: Lucee 5.4.5.23

2

Okay, I think I have figured out the issue is with the datasource connection validation and turning that off should fix the issue: [LDEV-3126] - Lucee But I’m not figuring out where to make that settings change described in the ticket. Does anyone know?

3

if you are referring to lucee.datasource.pool.validate this is a setting you pass to Lucee as a environment variable or system property.

How to set it up you can find at System Properties and Environment Variables :: Lucee Documentation

Unfortunately there have been some changes in the docs building that are breaking some pages of the docs at the moment . The oage above is one that has been affected.

Another reference about the specified setting can be found at:

4

Thanks Andreas! I was able to set it as a System Property. I performed the dumps mentioned in the document and those show that the property is being registered as expected. I can’t duplicate the issue on my dev machines but hopefully it will have the desired effect in Prod.

1 Like