reader: don't use Decimal class to calculate backoff

[virtuald]

It's not immediately clear why the Decimal class is being used here, when it seems like pure floats are just as good.

• Profiling indicates lots of time spent here, reduced 50000 messages
  from 23s to 18s (not raw NSQ timing, with custom layering on top)

Haven't ran the tests yet, going to let Travis do that for me :)

[virtuald]

Ok, I'll fix the tests... give me a few minutes.

[virtuald]

Ok, tests should pass this time. Because of the way backoff is used, I changed it around to use integers instead of floating point numbers, but the public API (get_interval()) still returns a floating point number. Slightly less speedup because of the conversion in get_interval, but still a huge win (20%).

[ploxiln]

You could probably get it to work with plain floats, with just a tweak: in the success case, instead of using max() to stop it at 0, use something like if interval < 1.0/1024: interval = 0

[virtuald]

As I said, this is still a 20% speedup over the current release, so I'm not too concerned. Knock yourself out if you want to get that extra 0.5%. 👍

[mreiferson]

I'm still really confused as to how it spent 20% of its time here - do you have any more logs or results you can paste from your profiling?

Backoff shouldn't be calculated so frequently?

[virtuald]

I don't have anything I can release publicly, but if you want I can put together a quick raw NSQ test that should duplicate the results.

First thing of course, is the Decimal class is slow compared to raw integers or floats. This is python after all, and this seems to be called in a critical section (or at least as shown below -- multiple times per message).

Looking at my profiling data, it shows that BackoffTimer.success is called 50001 times (which is equal to the number of messages received), and BackoffTimer.get_interval is called 100,040 times.

• success seems to be called by on_backoff_resume, which is called by trigger which is called by lots of people..
• get_interval seems to be called
  • 50001 times by maybe_update_rdy, called by _handle_message
  • 50001 times by enter_continue_or_exit_backoff, called by _on_backoff_resume

If that's unexpected, perhaps the backoff code needs some restructuring and we'd see even more performance boost. :)

[virtuald]

Alright, I put together a test using just NSQ that demonstrates the performance difference. It's not totally realistic, but good enough. :) See this gist.

Using this raw nsq reader/writer, and a local nsqd (no lookupd) on my macbook pro without power, I get:

• Python 2.7.10: 9.6s with my patch, and 13.8s without it
• Python 3.5.1: 10.5 with my patch, and 11.108 without it

Tornado 4.3 for both.

[mreiferson]

Thanks, I'm very surprised at this, but then again I've unfortunately never actually paid attention to some of these details.

What this tells me is that the problem isn't Decimal, it's the fact that we're interacting with this in critical code paths. We should fix that instead.

[virtuald]

Well. I'm open to someone refactoring the internals so that it's even faster. 👍

However, I don't feel comfortable enough with the way NSQ works to do the refactoring correctly, and this provides a sizable speed boost for me now. I'll leave it to you.

[mreiferson]

see #156, thanks for digging into this!