November 15, 2011

It’s about timing baby!

By Andreas Fast

Yeah, it’s about timing.

There was a problem in one of our projects at moove-it related to slow processing. There is a daemon spawning new threads to process certain new entries to the database. The entries come from a different system, that’s the reason for this program which processes each new entry. Sometimes at certain hours of a day there are peaks in the entries to the database and the process will fall behind by about 20.000 entries or more. So we started analyzing the code to understand what was happening and why it took so long. We noted that each new thread the daemon spawned took about 5 seconds to complete its task. As we narrowed the measurement we came up with some code that took 5 seconds to execute but it only involved access to the database. So thanks to Aaron Patterson’s (@tenderlove) talk at RubyConf Uruguay about “Who makes the best asado” where he talked about rails and how it manages threads and database connections, we knew where to look.

What he explained is that each new thread requests its own database connection from the connection pool, and if there isn’t a free connection, rails waits for about 5 seconds and if after that there is no free connection it iterates over all the threads to take back the connections of dead threads(more info). See the correlation with the 5 seconds I talked about in the previous paragraph? We immediately suspected that this was the problem. So we started searching the Rails API for a way to release the connection at the end of each thread’s execution. Surprisingly, we didn’t find an easy and understandable explanation anywhere at first googling ;), so we digged deeper and came up with the following line:

ActiveRecord::Base.connection_handler.clear_active_connections!

The ActiveRecord::Base.connection_handler method returns the connection handler for the current thread and the clear_active_connections method does what it looks like, or from the Rails doc: “Returns any connections in use by the current thread back to the pool, and also returns connections to the pool cached by threads that are no longer alive.”

So this line returns the connections in use by a thread to the pool and enables the new threads spawned by the daemon to use the freed connections. This way we avoid the 5 second wait for rails to free the connections for us.

This one line picked up our performance from processing 1.000 entries in almost 2 hours to processing 10.000 in 5 minutes. Nice huh?!

That’s it. I’m not sure if this is the best way of doing it since this method also “… returns connections to the pool cached by threads that are no longer alive.” I guess this means it does the iteration over all the threads Aaron mentioned, but as you can see I’m happy with the performance improvement. We are using Rails 3.0.5, Aaron said that he will change the behavior, read more about it here.

Special thanks to @cheloeloelo who helped detecting the problems and digging through the Rails API finding the proper method to free the connections.

Image: Suat Eman / FreeDigitalPhotos.net