Getting a connection from pool without actually running a query against it will leak it.

[NathanaelA]

If I grab a connection and never send a query on to the server this will leak the connection out of the pool. Once you hit the max (default is 10) - you are hosed. Not sure there is a lot that can be done about this, since you don't know why they got the connection and why it is still unused. Maybe add a debug mode timer to check how old all unused connections are and spit out an error in the event they are > 60 seconds. -- but at the minimum it probably should be documented somewhere.

Consideration for debugging purposes:
I added a "this.id = parseInt(Math.random()*10000,10);" to the client.js p.connect routine. Then I spit this # out on every pool log output. This allowed me to see the entire flow of a pooled connection (create, reuse, return, pause, drain, destruction) and find the missing connection. Then in my code I was able to do client.id to track it through my code. This was very useful for debugging purposes. You might also consider adding to your pool logging how many connections are out (count - available, including at the automated destruction routine how many are still "out").

[troyk]

What version are you using. If you look in lib/defaults.js poolIdleTimeout should be set to 30 seconds by default, meaning that after 30 seconds your client will be destroyed and thus removed from the pool, which should cause a new client to be created on the next call to connect.

Granted, this is probably not what you want either as you'll have a bunch of reconnects going on.

In a web app, I used to grab a client via connect in the middleware and attach it to the request object as a convenience to save a callback in the main "controller" function and ran into this same problem. My fix was to emit "drain" on the response.end, but ultimately I ended up just installing plv8 on the server as dealing with transactions in an async environment turns out to be a PITA. plv8 is very cool, has a synchronous workflow yet is very performant because no round trips to the server.

+1 for better logging, I've added logging queries to console, etc. Generic-pool used by node-postgres already has some debug logging, but it's not exposed via the node-postgres API. Pull request forth coming when I get my project in a deployable state!

[NathanaelA]

No, I'm aware of the poolIdleTimeout -- the issue is that if you do grab a connection from the pool; then don't do anything with it -- ie:

pg.connect(..., callback(err,client) {
// some corner case bypass sending any sql to server
if (x && y && z) return;

// Use my client to run query
client.query( ... );
}
);
In the case of x,y & z -- this "client" will be leaked from the pool because it never is used it is never put back into the pool to even be affected by the poolIdleTimeout or any other parameter.

However, like I said above I'm not sure a fix for this because I asked for the connection and until I use it pg library is making a "proper" assumption that I needed it, so because I haven't used it yet it leaves it alone. The only solution that seems worth while is adding some additional (on by default) warning logging would be good if the pool gets to 0 available connections available in the pool and the waiting connections is greater than 10% of the pool size.

Doing a drain emit, would work to return it to the pool. Might be better to have helper function that does this (i.e. client.finished(), client.returnToPool(), or client.unused() ) -- just something that documents this issue because at least no one on my team had a clue this could happen. And so it was a lengthly debug session to track it through our code back to this issue.

On the logging;
I'm willing to submit my additional logging (in debug mode) which basically shows the entire pool state at every connect so you can easily see if something is wrong in the pool. (i.e. my output is:
PGSQL dispensing connection, waiting clients=2, available in pool: 7, currently in use: 5
and
PGSQL acquiring Connection, Current Pool Count: 5 of 10, waiting in queue: 3

I can see immediately that I have 5 being used, and 3 waiting in the pool in a few seconds I would expect the numbers to be somewhere around (since those three waiting in the queue will create 3 new connections)
PGSQL Acquiring Connection, Current Count: 8 of 10, waiting in queue: 0

But if I see (frequently):
PGSQL Acquiring Connection, Current Count: 10 of 10, waiting in queue: 7
Then I realize that I have a couple issues; Too small of a pool. And a potential queue leak, if the 10 of 10 never drops to 0 or 1 of 10, then I know I have a leak and need to turn on additional logging to find it. :)

In addition the additional debug logging has an random "id" associated with every connection; so that I can see which connection leaked and who called it. (this.id = parseInt(Math.random()*10000,10); at client connection creation) -- All the logging has the "id" with it so that I can easily trace a id through the log, when it is returned to the pool, any re-use, and finally its cleanup

As for the plv8 -- that is very cool, I'm going to have to look into that, I hadn't see that project, thx! :)

[brianc]

+1 for exposing the built in pool logging from node-pool since it's already there. As for adding debugging logging into node-postgres in other places I'm not a fan of that. If you really want to add logging you can monkey patch around the methods you need to log. Or log when you call into the node-postgres library. I find having different modules all log a different way is annoying (like the way express and socket.io log for you by default). Logging should be handled in the application layer since it's infinitely varied depending on the needs and likes of the developer reading the log.

I view requesting a connection from the pool and not using the connection as a code bug, actually. If you take a connection from the pool you better use it. If you don't use it you can manually emit a drain event from the connection I suppose to give the connection back to the pool. In your example the

// some corner case bypass sending any sql to server
if (x && y && z) return;

Should be moved outside of the pg.connect call. If it absolutely can't you can always call client.emit('drain') to signal you're done. Any automatic check in thing of "idle" connections is going to lead to inteterminate behavior in the case where someone actually wanted to keep 1 of the connections checked out from the pool for a "very long time" for whatever reason (i.e. using a client.query('LISTEN event_name') on one of the connections)

[NathanaelA]

Oh, I don't disagree Brian -- that is the best solution; I am verifying outside the connect that none of the variables that typically get built and sent to the server are not null and then bypassing the connect in the event that all of them are null. :-) And I would also consider it a bug in our code also. However, this is a nasty gotcha if you don't know about it. I fully understand the reasoning why it works the way it does and I'm not advocating any sweeping changes; all I'm advocating is something like

Adding a simple:
(psedo-code) if (count == factory.max && waiting > factory.max/4) console.warn("Potential connection leak in pgpool, or your pool size should be increased.");

Which would be a simple quick debug code to make sure that this is caught early rather than much, much later after a very long debug session. :-)

My team probably won't get caught by this again; I want to make sure tomorrow someone else doesn't get caught by it.

[mouna-apperson]

We were also caught by this. In our previous code base (before we added caching) we fetched a database connection for each user request. In the cases where one wasn't used because the user made an invalid request, the connection was leaked. Until I saw this issue, we never actually took the time to find this problem. Now that we ask for connections lazily, it all works.

However, I think the way this pool functions is fundamentally broken. Having the pool code guess when to free the connection is alright only if it 100% correct. Since it isn't, it should not accept that responsibility. If it were me, I'd make the connection objects proxies that are actually connected when they are first used. That way, you wouldn't leak them.

Also, putting a warning somewhere might also be a good idea.

[brianc]

I like the idea of returning a proxy which only connects if it receives a query.

[strk]

Did the debug code ever enter the codebase ? I've code starving while waiting for a callback after exactly 5 connection failures and wondering if it's due to thi problem..

[brianc]

It hasn't entered the codebase. Do you have a failing test case for this?

[strk]

On Fri, Jul 13, 2012 at 08:51:02AM -0700, Brian Carlson wrote:

It hasn't entered the codebase. Do you have a failing test case for this?

Not really. I'm cheasing an heisenbug but can't really tell yet if it's rooted
in node-postgresql: CartoDB/CartoDB-SQL-API#38

--strk;

[strk]

On Fri, Jul 13, 2012 at 06:04:56PM +0200, strk wrote:

On Fri, Jul 13, 2012 at 08:51:02AM -0700, Brian Carlson wrote:

It hasn't entered the codebase. Do you have a failing test case for this?

Not really. I'm cheasing an heisenbug but can't really tell yet if it's rooted
in node-postgresql: CartoDB/CartoDB-SQL-API#38

Oh, by the way, the tests do run fine for me, but I guess none of the tests
actually communicate with a PostgreSQL server, right ?
(talking about make test)

--strk;

[brianc]

try make test-all connectionString=pg://username:password@host:5432/database

make test only runs the unit tests, not the integration tests

[strk]

On Fri, Jul 13, 2012 at 01:06:59PM -0700, Brian Carlson wrote:

try make test-all connectionString=pg://username:password@host:5432/database

Ah, great!

May I suggest to have the required tables created as part of it ?
To avoid this:

It is possible you have not yet run the table create script under script/create-test-tables

--strk;

[brianc]

I'm going to talk to felixge sometime soon about connection pooling and hopefully have a little more elegant solution once we put our heads together

[booo]

@NathanaelA asked for a client.release function. If we can just fake a drain event this should be easy to implement. What do you think?

[brianc]

Yeah, I think the methods on the pooled clients dealing with checking in/checking out should semantically match the actual operations. I've been thinking a lot about this recently and it will probably require a new-ish API for using the pool. I'm thinking actually of implementing the pool in a stand-alone module, but I'm still not sure about that. What do you propose the client.release function would do?