Requests stall for several seconds in authenticators' SQL connection pool

[zuk]

Reported by another user:

We're using RubyCAS server 1.0.1 with RubyCAS Client 2.3.8 and several
Rails apps.
It's working correctly, but we're often seeing stalls of several
seconds when directly authenticating to the server,
or obtaining, or using proxy tickets.

It happens virtually every time in test and development, under no
other load eg locally.

Here is the log, starting at when the browser hit is made. The stall
is 5 seconds between the first two localization logs.
This happens on the first request, and any other request (ie, the
rubycas server is not "warming up").

Additional info:

If I set the number of connections to 10, then hit it with 11 fast
requests, the last hangs.
The connections are not being returned to the pool in a timely manner.

Changing the "timeout" config param appears to make no difference.

More connections is not a prod fix though... Can you replicate the
issue?
We see it with the above version, with Ruby 1.9.2 and 1.9.3

[incorvia]

I notice a significant slow down every.. 4 -5 requests.. where authentication will take around 1 second for the first 4 and then take about 5 seconds for the last.. I wonder if this is related..

[incorvia]

This may be related to this: https://rails.lighthouseapp.com/projects/8994/tickets/5736-connections-not-released-in-rails-3

I did notice that if I call:

ActiveRecord::Base.connection_pool.clear_stale_cached_connections!()

From inside a thread it will not in the snag on the 4 / 5 request.

[incorvia]

I fixed this for myself by adding a before filter to to server.rb:

https://gist.github.com/

I see it as a workaround but I can offer a pull request if needed.

[zuk]

Can you post the link to the gist? I think you missed the gist id in that URL.

[incorvia]

Ha so I did.. sorry.. and it's an after_save not a before_save:

https://gist.github.com/9b2e19b322fd78ad0b45

I added this next to the before_save in server.rb

[zuk]

Any idea how this works? From what I can tell this would just force ActiveRecord to open a new connection to the mysql server instead of reusing the existing one.

I guess I just don't understand what the problem is exactly... I thought it was due to the pool getting exhausted and the AR adapter having to open new connections to mysql. But if this fixes things for you then the delay can't be from opening new connections...

Hmm maybe it's caused by AR trying to use a closed/dead connection? i.e. it tries to talk to mysql, waits a few seconds for a response, gives up and opens a new one?

I can't look into this right now but hopefully this might set someone else on the right path.

[zuk]

Any idea how this works? From what I can tell this would just force
ActiveRecord to open a new connection to the mysql server instead of
reusing the existing one.

I guess I just don't understand what the problem is exactly... I thought it
was due to the pool getting exhausted and the AR adapter having to open new
connections to mysql. But if this fixes things for you then the delay can't
be from opening new connections...

Hmm maybe it's caused by AR trying to use a closed/dead connection? i.e. it
tries to talk to mysql, waits a few seconds for a response, gives up and
opens a new one?

I can't look into this right now but hopefully this might set someone else
on the right path.

On Fri, Jul 20, 2012 at 2:09 PM, incorvia <
reply@reply.github.com

wrote:

Ha so I did.. sorry.. and it's an after_save not a before_save:

https://gist.github.com/9b2e19b322fd78ad0b45

I added this next to the before_save in server.rb

---

Reply to this email directly or view it on GitHub:
#102 (comment)

[incorvia]

I'm kind of new to this, so I found a quite good article on this here:

http://www.daniel-azuma.com/blog/archives/216

Specifically the section on Managing Connectoins and the connection pool. The main gist of it is that AR will setup a pool of connections. He says: "When a task needs a database connection, it checks one out of the pool; when it finishes, it checks the connection back in so that the next task can use it.". He adds that in Rails this happens automatically but if we are using AR's API we need to check these back into the connection pool after each request.

If we don't.. when a request comes in.. there are no connections in the pool available it must wait for another to become available or 'timeout' which is 5 seconds. See: http://bibwild.wordpress.com/2011/11/14/multi-threading-in-rails-activerecord-3-0-3-1/

The call I recommended: ActiveRecord::Base.connection_pool.release_connection releases the current connection back to the pool so it is available to subsequent threads.

That's my understanding anyways! And someone can correct me if I'm mistaken.

[infoman]

Unfortunately that gist didn't help me and almost all requests are still delayed 5 seconds. I'm using Passenger on nginx as server and Ruby 2.0.0.

Any other possible fixes?