Tuesday, November 20, 2012

Better tracing of Npgsql connection pool usage in the works



Sometimes, Npgsql users receive errors when working with connection pooling. The problem appears when they try to open a new connection and receive the following message: 

"Timeout while getting a connection from pool."

This is caused when an attempt is made to get a connection from a pool which  has all its connections used. Most of the time this problem is a difficult one to track because it generally happens when the system is in production and not in the development phase. Of course. :)

Some time ago, I received a report from Miłosz Kubański about such a problem. I told him I would work in a way to get more information so we could check what was happening.

In order to help us find the problem, I added a little "hack" to Npgsql: Whenever an error while getting a connection from the pool occurs, Npgsql would log a stacktrace of the allocation of all the connections which were in the pool. Theoretically, those connections which were allocated should not be retained and by taking a "snapshot" of those allocations, we could get some tips about which code allocated the connection and check for potential missing releases.

Last week I sent Milosz this modified version of Npgsql so he could give it a try and send me back the log. Yesterday he sent me the log. Inside it, I chose two stacktraces and asked him if would be possible there was any missing close.

Milosz replied saying there was indeed a missing close call. It was an exception inside a very complex system. 

Based on this feedback, I think this "hack" has shown to be very useful in future cases and I'll work to get this change in a "non-hack" status and add it to Npgsql code. I hope this helps Npgsql users to find possible causes for connection pooling problems.

When this feature is available I'll let you know.



7 comments:

Matthew B said...

This would be very useful -- any timeframe on when this feature will be available?

Rui Guimarães said...

This seams really useful. Do you have any update on this?

Peter van Soest said...

Francisco, did the "hack" ever made it to Npgsql 2.1.0 or 2.1.1?

Francisco Figueiredo Jr. said...

Hi all!

Sorry, but this feature isn't present in current Npgsql release. I'm working to add it to master branch and I hope it will be present in the 2.2 release.

Chris Nickel said...

Hi, This 'Hack' would be useful for an issue we are investigating right now. Is this logging available in the 2.2 beta 1 release?

Thanks.

Francisco Figueiredo Jr. said...

Hi, all!

We have an issue open on github about that:
https://github.com/npgsql/Npgsql/issues/237

I already have a patch to include this feature. Unfortunately, I think it will be present in the 2.3 release as the 2.2 is already in the RC phase.

Please, check the 237 issue above for news about this feature. I'll update the patch so it can be cleanly applied and you all can test it. This would be very helpful.

Thanks in advance and sorry for not having this feature released yet.

Francisco Figueiredo Jr. said...

I just added more information to the issue tracker. I also updated the patch and created binaries with this patch applied which you can give it a try.
Check out https://github.com/npgsql/Npgsql/pull/311 for more info.

I hope it helps.