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

SharedTimer race condition #2084

Closed
mmimica opened this issue Feb 28, 2023 · 4 comments · Fixed by #2085
Closed

SharedTimer race condition #2084

mmimica opened this issue Feb 28, 2023 · 4 comments · Fixed by #2085

Comments

@mmimica
Copy link
Contributor

mmimica commented Feb 28, 2023

Driver version

12.2.0.jre11

Problem description

There is a race-condition in SharedTimer class.

The class holds a singleton instance of a ScheduledThreadPoolExecutor and keeps a reference count. It disposes the executor instance when reference count reaches 0. Because of ineffective use of double-lock check pattern in SharedTimer#getTimer the reference counter is prone to race-conditions.

The problem escalates with dawn of "Connection Resiliency" feature which is enabled by default. It can be mitigated by setting connectRetryCount connection property to 0.

mmimica pushed a commit to mmimica/mssql-jdbc that referenced this issue Feb 28, 2023
@mmimica
Copy link
Contributor Author

mmimica commented Feb 28, 2023

Introduced by #1931

@Jeffery-Wasty
Copy link
Contributor

Hi @mmimica,

Thank you for finding this, we'll take a look at the issue and the PR and get back to you on how we'd like to proceed.

@Jeffery-Wasty Jeffery-Wasty linked a pull request Feb 28, 2023 that will close this issue
@jubax
Copy link

jubax commented Mar 13, 2023

I think I stumbled over this problem in production since upgrading from 11.2.2 to 12.2.0. See the stack trace below:

java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@297df4d2[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@40b78b8e[Wrapped task = com.microsoft.sqlserver.jdbc.TDSTimeoutTask@445ae498]] rejected from java.util.concurrent.ScheduledThreadPoolExecutor@6aafff45[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
	at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2065) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:833) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:340) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:562) ~[?:?]
	at com.microsoft.sqlserver.jdbc.SharedTimer.schedule(SharedTimer.java:144) ~[mssql-jdbc-12.2.0.jre11.jar:?]
	at com.microsoft.sqlserver.jdbc.SharedTimer.schedule(SharedTimer.java:134) ~[mssql-jdbc-12.2.0.jre11.jar:?]
	at com.microsoft.sqlserver.jdbc.TDSCommand.startResponse(IOBuffer.java:8074) ~[mssql-jdbc-12.2.0.jre11.jar:?]
	at com.microsoft.sqlserver.jdbc.SQLServerStatement.doExecuteStatement(SQLServerStatement.java:918) ~[mssql-jdbc-12.2.0.jre11.jar:?]
	at com.microsoft.sqlserver.jdbc.SQLServerStatement$StmtExecCmd.doExecute(SQLServerStatement.java:814) ~[mssql-jdbc-12.2.0.jre11.jar:?]
	at com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:7685) ~[mssql-jdbc-12.2.0.jre11.jar:?]
	at com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:4048) ~[mssql-jdbc-12.2.0.jre11.jar:?]
	at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeCommand(SQLServerStatement.java:272) ~[mssql-jdbc-12.2.0.jre11.jar:?]
	at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeStatement(SQLServerStatement.java:246) ~[mssql-jdbc-12.2.0.jre11.jar:?]
	at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeQueryInternal(SQLServerStatement.java:743) ~[mssql-jdbc-12.2.0.jre11.jar:?]
	at com.microsoft.sqlserver.jdbc.SQLServerConnection.isValid(SQLServerConnection.java:7077) ~[mssql-jdbc-12.2.0.jre11.jar:?]
	at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:147) ~[HikariCP-java7-2.4.13.jar:?]
	at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:169) ~[HikariCP-java7-2.4.13.jar:?]
	at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:145) ~[HikariCP-java7-2.4.13.jar:?]
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:85) ~[HikariCP-java7-2.4.13.jar:?]
    ... (cut of proprietary classes from trace)

@mmimica
Copy link
Contributor Author

mmimica commented Mar 13, 2023

Yes, this is the usual consequence. Setting connectRetryCount=0 didn't really help as I initially said.

Jeffery-Wasty pushed a commit that referenced this issue Mar 14, 2023
* Merge dev to master for 9.2.0 release (#1506)

Merge dev to master for 9.2.0 release (#1506)

* fix merge

* Fix #2084 by not using double-lock check.

* Simplify the test a bit.

* Simplify the test a bit.

* test rewritten for old compatibility

---------

Co-authored-by: ulvii <v-ulibra@microsoft.com>
Co-authored-by: Peter Bae <v-hyba@microsoft.com>
Co-authored-by: Milan Mimica <milan.mimica@infobip.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants