defunkt/resque — Issue #427: [Performance] Resque#after_enqueue_hook takes up 81% of the Resque#enqueue processing time
Author: jeznet
Created: 2011-10-13 10:58:29+00:00
State: open

I have done some profiling of Resque#enqueue and I found a strange thing - Resque#after_enqueue_hook takes up 81% of the enqueue process. Here are some measurements (an illustration of it):

[ProfilerGraph](http://www.diigo.com/item/image/1uudk/b305?size=o)

According to the profiler this line takes up the most time:

```
if hook =~ /perform$/
```

The profiling was using RubyProof at Ruby1.9.2p290 with gcdata patch with this command:

```
export OUTPUT_FILE=tmp/performance/Resque#enqueue.KCachegrind && RAILS_ENV=production bundle exec rails runner 'RubyProf.start; 1000.times{ Resque.enqueue(Job::Log, Time.now, Time.now.nsec, :debug, "This is a test.", {:test => "It has to be."}) }; result = RubyProf.stop; printer = RubyProf::CallTreePrinter.new(result); printer.print(File.new(ENV["OUTPUT_FILE"], "w"));' && kcachegrind $OUTPUT_FILE
```

with resque (1.15.0) @ Redis (2.2.11 ). With the newest version of Resque it performs even worse because it calls also a before hook.
I do not use any Resque hooks or plugins.

BTW: I found all this during profiling of an ap that I work on. I was trying to move some data (with logs) writes to a DB to a job, and to my surprise it was slower than doing the quite expensive write directly. Now I'm using Resque#push to enqueue those db write jobs.