Recently, I have been working on moving some processes from the request-response web cycle to a MongoMapper-backedDelayed::Job. Everything seem to go smoothly, but it seemed that there was some slowness actually queuing the jobs. Here is how I got to the bottom of it.
Benchmarking
First, I wrote a very basic benchmark to see if indeed queuing was slow:
Pushing the simplest job to the queue takes an average of 0.1832 seconds per push. Slow indeed.
Profiling
To get to the actual source of slowness, I read up on jRuby Profiling. Note that it is imperative to use set ```JRUBY_OPTS=‘–profile’ for the following to work:
From the above it’s cleat that were we are spending the bulk of the time is in ConditionVariable#wait. From the documentation:
ConditionVariable objects augment class Mutex. Using condition variables, it is possible to suspend while in the middle of a critical section until a resource becomes available.
Focusing on the immediate previous calls, we can see that it looks like the Mongo::Pool is having a hard time with the checkout. Hmm… how many connections are there by default? It turns out, that it’s just 1.
After tweaking the Mongo connection url to increase the number of connections (to 5) and running our benchmark again: