Debugging leaking connections

[chau...@gmail.com]

Hi,

I am currently porting an old application (Java 1.4) to newer VMs and changing persistent MySQL connections to HikariCP. So far the progress is good but I found a large number of connections created somewhere in my code by I cannot trace it down.

Is it possible to look into the active connection held by the connection pool programmatically? Using MySQL log is tedious and ineffective in my case as I have 5k+ statement every second...

I believe there's some good way to fetch the content of these connections as the engine can detect pool leak as well.

Thanks,
DC

[Brett Wooldridge]

This is pretty simple, just set leakDetectionThreshold to something like one minute (60000ms), and HikariCP will log stacktrace if a Connection is taken but not returned.  Using the stacktrace, you can see exactly where in you application the connection leak occurred.

-Brett

[chau...@gmail.com]

Hi Brett,

Sadly I have not receiving any stacktrace when I used setLeakDetectionThreshold(5000). Here's the output of my log (Log4J 2)

Sync-DEBUG [pool-3-thread-17] 2015-04-21 18:07:56 (JConfig.java:317) - JConfig - getDesc - start
Sync-DEBUG [pool-3-thread-17] 2015-04-21 18:07:56 (JConfig.java:360) - JConfig - getDesc - end
Sync-DEBUG [pool-3-thread-17] 2015-04-21 18:07:56 (JConfig.java:317) - JConfig - getDesc - start
Sync-DEBUG [pool-3-thread-17] 2015-04-21 18:07:56 (JConfig.java:360) - JConfig - getDesc - end
LeakTask- WARN [Hikari Housekeeping Timer (pool HikariPool-0)] 2015-04-21 18:07:56 (LeakTask.java:88) - Connection leak detection triggered for connection com.mysql.jdbc.Connection@1ccf24c, stack trace follows
Sync-DEBUG [pool-3-thread-3] 2015-04-21 18:07:56 (JConfig.java:317) - JConfig - getDesc - start
Sync-DEBUG [pool-3-thread-3] 2015-04-21 18:07:56 (JConfig.java:360) - JConfig - getDesc - end
Sync-DEBUG [pool-3-thread-3] 2015-04-21 18:07:56 (JConfig.java:317) - JConfig - getDesc - start
Sync-DEBUG [pool-3-thread-3] 2015-04-21 18:07:56 (JConfig.java:360) - JConfig - getDesc - end

Anything I need to do with Log4J / SLF4J in order to capture that stacktrace?


I am working around in creating a wrapper class logging all connections so far... Functional but performance cost is extremely high.

Thanks,
DC

[Brett Wooldridge]

This seems likely to be a logging configuration issue, you are using the log4j-slf4j-impl-2.0.jar bindings correct?  Do you have a Log4J 2 logging pattern that might exclude stacktraces?  Such as alwaysWriteExceptions=false, %throwable{none}, %throwable{0}, etc?  Are you using TCP or UDP socket logging?

-Brett

On Wednesday, April 22, 2015 at 10:03:51 AM UTC+9, chau...@gmail.com wrote:

Hi Brett,

Sadly I have not receiving any stacktrace when I used setLeakDetectionThreshold(5000). Here's the output of my log (Log4J 2)...

[chau...@gmail.com]

I am logging into files, and I am getting stack traces normally on other classes. So there's should be no problem for logger configuration.

In the meantime I have found the problem using caches. Thanks ; )

N.B.  Hikari CP works great in Celeron 700Mhz :D

[Brett Wooldridge]

Glad you found the leak, and great to hear that HikariCP runs great on your Celery ... er, Celeron ... 700MHz. :P

Still a bit troubled by the logging issue.  Is everything going through slf4j (and then into log4j 2)?   Or is the majority of logging directly to log4j, and only HikariCP is going through slf4j?

-Brett

[chau...@gmail.com]

I used log4j-slf4j-impl. I had a hard time configuring the logger to log to different file but no luck. I wrote a custom log4j configuration factory but it seems I cannot modify the log setting dynamically.

See if in future HikariCP allows user to use their own LogFactory and allow better flexibility in this. This would significantly improve debugging, and some system performance as well.