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

Possible Race Condition on Shutdown #128

Closed
dharrigan opened this issue Jul 30, 2014 · 2 comments
Closed

Possible Race Condition on Shutdown #128

dharrigan opened this issue Jul 30, 2014 · 2 comments
Labels

Comments

@dharrigan
Copy link
Contributor

Hi,

Continuing on from the forums, thought I might as well open an issue for tracking purposes.

I'm seeing this now and again when I shutdown (ctrl+c) my Spring application (using HikariCP as the datasource provider):

[2014-07-30 18:06:55.004][               ][DEVELOPMENT][WARN ][com.zaxxer.hikari.pool.HikariPool       ][279 ] - Internal accounting inconsistency, totalConnections=-2
java.lang.Exception: null
    at com.zaxxer.hikari.pool.HikariPool.closeConnection(HikariPool.java:279) [HikariCP-2.0.1.jar:na]
    at com.zaxxer.hikari.pool.HikariPool.releaseConnection(HikariPool.java:221) [HikariCP-2.0.1.jar:na]
    at com.zaxxer.hikari.proxy.ConnectionProxy.close(ConnectionProxy.java:343) [HikariCP-2.0.1.jar:na]
    at com.zaxxer.hikari.util.PoolUtilities.quietlyCloseConnection(PoolUtilities.java:18) [HikariCP-2.0.1.jar:na]
    at com.zaxxer.hikari.pool.HikariPool.lambda$abortActiveConnections$5(HikariPool.java:478) [HikariCP-2.0.1.jar:na]
    at com.zaxxer.hikari.pool.HikariPool$$Lambda$63/633170599.accept(Unknown Source) [HikariCP-2.0.1.jar:na]
    at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) [na:1.8.0_11]
    at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1359) [na:1.8.0_11]
    at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:512) [na:1.8.0_11]
    at java.util.stream.ForEachOps$ForEachTask.compute(ForEachOps.java:290) [na:1.8.0_11]
    at java.util.concurrent.CountedCompleter.exec(CountedCompleter.java:731) [na:1.8.0_11]
    at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289) [na:1.8.0_11]
    at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:902) [na:1.8.0_11]
    at java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1689) [na:1.8.0_11]
    at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1644) [na:1.8.0_11]
    at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157) [na:1.8.0_11]
[2014-07-30 18:06:55.007][               ][DEVELOPMENT][INFO ][o.s.s.concurrent.ThreadPoolTaskScheduler][203 ] - Shutting down ExecutorService 'taskScheduler'

Comments from Brett suggest that this could be a race condition.

https://groups.google.com/forum/?hl=en-GB#!topic/hikari-cp/Dfpn8iaZxkA

-=david=-

@brettwooldridge
Copy link
Owner

It wasn't a race condition, merely an accounting issue decrementing the totalConnections count when aborting connections. This fix will be in the next release of HikariCP. It is available now on the dev branch.

@dharrigan
Copy link
Contributor Author

Thank you :-)

-=david=-

On 31 July 2014 06:07, Brett Wooldridge [email protected] wrote:

It wasn't a race condition, merely an accounting issue decrementing the
totalConnections count when aborting connections. This fix will be in the
next release of HikariCP. It is available now on the dev branch.


Reply to this email directly or view it on GitHub
#128 (comment)
.

I prefer encrypted and signed messages. KeyID: B20A22F9
Fingerprint: 110A F423 3647 54E2 880F ADAD 1C52 85BF B20A 22F9

"It is not usually until you've built and used a version of the program
that you understand the issues well enough to get the design right." - Rob
Pike, Brian Kernighan.

No trees were harmed in the sending of this message, however, a number of
electrons were inconvenienced.

gbehrmann added a commit to gbehrmann/dcache that referenced this issue Mar 6, 2015
IN2P3 reported the following failure:

04 Mar 2015 20:42:12 (SrmSpaceManager) [door:gridftp-ccdcatli013-81197@gridftp-ccdcatli013Domain:1425495819459 gridftp-ccdcatli013-81197 PoolAcceptFile 000078810A3673A644A286B0EFC8D4C69356] Internal accounting inconsistency, totalConnections=-1
java.lang.Exception: null
	at com.zaxxer.hikari.pool.HikariPool.closeConnection(HikariPool.java:268) [HikariCP-1.3.9.jar:na]
	at com.zaxxer.hikari.pool.HikariPool.releaseConnection(HikariPool.java:210) [HikariCP-1.3.9.jar:na]
	at com.zaxxer.hikari.proxy.ConnectionProxy.close(ConnectionProxy.java:313) [HikariCP-1.3.9.jar:na]
	at org.springframework.jdbc.datasource.DataSourceUtils.doCloseConnection(DataSourceUtils.java:341) [spring-jdbc-4.0.5.RELEASE.jar:4.0.5.RELEASE]
	at org.springframework.jdbc.datasource.DataSourceUtils.doReleaseConnection(DataSourceUtils.java:328) [spring-jdbc-4.0.5.RELEASE.jar:4.0.5.RELEASE]
	at org.springframework.jdbc.datasource.DataSourceUtils.releaseConnection(DataSourceUtils.java:294) [spring-jdbc-4.0.5.RELEASE.jar:4.0.5.RELEASE]
	at org.springframework.jdbc.datasource.DataSourceTransactionManager.doCleanupAfterCompletion(DataSourceTransactionManager.java:326) [spring-jdbc-4.0.5.RELEASE.jar:4.0.5.RELEASE]
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.cleanupAfterCompletion(AbstractPlatformTransactionManager.java:1012) [spring-tx-4.0.5.RELEASE.jar:4.0.5.RELEASE]
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:879) [spring-tx-4.0.5.RELEASE.jar:4.0.5.RELEASE]
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:826) [spring-tx-4.0.5.RELEASE.jar:4.0.5.RELEASE]
	at org.springframework.transaction.interceptor.TransactionAspectSupport.completeTransactionAfterThrowing(TransactionAspectSupport.java:496) [spring-tx-4.0.5.RELEASE.jar:4.0.5.RELEASE]
	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:266) [spring-tx-4.0.5.RELEASE.jar:4.0.5.RELEASE]
	at org.springframework.transaction.aspectj.AbstractTransactionAspect.ajc$around$org_springframework_transaction_aspectj_AbstractTransactionAspect$1$2a73e96c(AbstractTransactionAspect.aj:63) [spring-aspects-4.0.5.RELEASE.jar:4.0.5.RELEASE]
	at diskCacheV111.services.space.SpaceManagerService.processMessageTransactionally(SpaceManagerService.java:488) [dcache-core-2.10.18.jar:2.10.18]
	at diskCacheV111.services.space.SpaceManagerService.processMessage(SpaceManagerService.java:452) [dcache-core-2.10.18.jar:2.10.18]
	at diskCacheV111.services.space.SpaceManagerService.access$000(SpaceManagerService.java:107) [dcache-core-2.10.18.jar:2.10.18]
	at diskCacheV111.services.space.SpaceManagerService$2.run(SpaceManagerService.java:413) [dcache-core-2.10.18.jar:2.10.18]
	at org.dcache.util.CDCExecutorServiceDecorator$1.run(CDCExecutorServiceDecorator.java:104) [dcache-core-2.10.18.jar:2.10.18]
	at org.dcache.util.BoundedExecutor$Worker.run(BoundedExecutor.java:211) [dcache-core-2.10.18.jar:2.10.18]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_51]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_51]
	at java.lang.Thread.run(Thread.java:744) [na:1.7.0_51]

This looks like the following HikariCP bug: brettwooldridge/HikariCP#128

This patch upgrades HikariCP to version 2.0.1, the same version we use in 2.11.

Target: 2.10
Require-notes: yes
Require-book: no
Acked-by: Tigran Mkrtchyan <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants