Requests Per Second »

Created at: 06.01.2009 09:12, source: The Rails Way - Home, tagged: performance scalability speed

One of the most harmful things about people discussing the performance of web applications is the key metric that we use. Requests per second seems like the obvious metric to use, but it has several insidious characteristics that poison the discourse and lead developers down ever deeper rabbit holes chasing irrelevant gains. The metric prevents us from doing A/B comparisons, or discussing potential improvements without doing some mental arithmetic which appears beyond the capabilities of most of us.

Instead of talking about requests per second, we should always be focussed on the duration of a given request. It’s what our users notice, and it’s the only thing which gives us a notice.

I should prefix the remaining discussion here by saying that most of it does not apply to discussing performance problems at the scale of facebook, google or yahoo. The thing is, statistically speaking, none of you are building applications that will operate at that scale. Sorry if I’m the one who broke this to you, but you’re not building the next google :).

I should also state that requests per second is a really interesting metric when considering the throughput of a whole cluster. But throughput isn’t performance.

Diminshing marginal returns

The biggest problem I have with requests per second is the fact that developers seem incapable of knowing when to stop optimising their applications. As the requests per second get higher and higher, the improvements become less and less relevant. This lets us think we’ve defeated that pareto guy, while we waste ever-larger amounts of our employers’ time.

Let’s take two different performance improvements and compare them using both duration and req/s.

Patch Before After Improvement
A 120 req/s 300 req/s 180 req/s
B 3000 req/s 4000 req/s 1000 req/s

As you can see, when you use req/s as your metric, change B seems like a MUCH bigger saving. It improves performance by 1000 requests a second instead of that measly 180, give that guy a raise! But let’s see what happens when we switch to using durations:

Patch Before After Improvement
A 8.33 ms 3.33 ms 5 ms
B 0.33 ms 0.25 ms 0.08 ms

You see that the actual changes in duration in B is vanishingly tiny. 8% of one millisecond! Odds are that that improvement will vanish into statistical noise when compared to the latency of your network, or your user’s internet connection.

But when we use requests per second, that 1000 is so big and enticing that developers will do almost anything to get it. If they used durations as their metric, they’d probably have spent that time implementing a neat new feature, or responding to customer feedback.

Deltas become meaningless

A special case of my first complaint is that with requests per second the deltas aren’t meaningful without knowing the start and the finish points. As I showed above, a 1000 req/s change could be a tiny change, but it could also be an amazing performance coup. Take this next example:

Before After Diff
1 req/s 1001 req/s 1000 req/s

When expressed as durations you can see that it made a huge difference

Before After Diff
1000 ms 0.99 ms 999.01 ms

So 1000 requests per second could either be irrelevant, or fantastic. Durations don’t have this problem at all. 0.02ms is obviously questionable, and 999.01 ms is an obvious improvement.

This problem most commonly expresses itself when people say “that changeset took 50 requests per second off my application”. Without the before and after numbers, we can’t tell if that’s a big deal, or if the guy needs to take a deep breath and get back to work.

The numbers don’t add up

Finally, requests per second don’t lend themselves nicely to arithmetic, and make developers make silly decisions. The most common case I see this is when comparing web servers to put in front of their rails applications. The reasoning goes something like this:

Nginx does over 9000 requests per second, and apache only does 6000 requests per second!! I’d better use nginx unless I want to pay a 3000 requests per second tax.

When people do this comparison they seem to believe that by switching to nginx from apache their application will go from 100 req/s to 3100 req/s. As always, durations tell us a different story.

Apache Nginx Diff
6000 req/s 9000 req/s 3000 req/s
0.16 ms 0.11 ms 0.05 ms

So we can see that odds are you’ll only gain a 5% of a millisecond’s improvement when switching. Perhaps that improvement is worthwhile for your application, but is it worth the additional complexity?

Conclusion

Durations are a much more useful, and more honest, metric when comparing performance changes in your applications. Requests per second is too wide-spread for us to stop using it entirely, but please don’t use it when talking about performance of your web applications or libraries.


more »

Avoid using metaprogramming (seriously!) »

Created at: 04.05.2008 11:29, source: Rails on the Run - Home, tagged: benchmark merb metaprogramming speed

Ruby is sexy, Ruby is cool and its metaprogramming potential offers some really cook features. However you might not realize that your cleverness is slowing down your code.

Today I was working on cleaning up merb_helper a Merb plugin that brings a lot of the stuff Rails developers are used to. In Merb we aim for speed and try to avoid magic.

merb_plugin didn't receive a lot of love from the main contributors but few features were added by different contributors and the code became hard to maintain.

Looking at the code I quickly found this bad boy:

(Old Merb Time DSL using metaprogramming)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21

   
  module MetaTimeDSL

    {:second => 1, 
     :minute => 60, 
     :hour => 3600, 
     :day => [24,:hours], 
     :week => [7,:days], 
     :month => [30,:days], 
     :year => [364.25, :days]}.each do |meth, amount|
      define_method "m_#{meth}" do
        amount = amount.is_a?(Array) ? amount[0].send(amount[1]) : amount
        self * amount
      end
      alias_method "m_#{meth}s".intern, "m_#{meth}"
    end

  end
  Numeric.send :include, MetaTimeDSL

The above code looks awful to me and I decided to rewrite it a way I thought would be more efficient:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41

  module TimeDSL

    def second
      self * 1
    end
    alias_method :seconds, :second

    def minute
      self * 60
    end
    alias_method :minutes, :minute

    def hour
      self * 3600
    end
    alias_method :hours, :hour

    def day
      self * 86400
    end
    alias_method :days, :day

    def week
      self * 604800
    end
    alias_method :weeks, :week

    def month
      self * 2592000
    end
    alias_method :months, :month

    def year
      self * 31471200
    end
    alias_method :years, :year

  end
  Numeric.send :include, TimeDSL

To make sure I was right, I run the following benchmarks:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127

require 'benchmark'
TIMES = (ARGV[0] || 100_000).to_i

Benchmark.bmbm do |x|
  
  x.report("metaprogramming 360.seconds") do
    TIMES.times do    
      360.m_seconds
    end
  end
  
  x.report("no metaprogramming 360.hours") do
    TIMES.times do
      360.seconds
    end
  end
  
  x.report("metaprogramming 360.minutes") do
    TIMES.times do    
      360.m_minutes
    end
  end
  
  x.report("no metaprogramming 360.minutes") do
    TIMES.times do
      360.minutes
    end
  end
  
  x.report("metaprogramming 360.hours") do
    TIMES.times do    
      360.m_hours
    end
  end
  
  x.report("no metaprogramming 360.hours") do
    TIMES.times do
      360.hours
    end
  end
  
  x.report("metaprogramming 360.days") do
    TIMES.times do    
      360.m_days
    end
  end
  
  x.report("no metaprogramming 360.days") do
    TIMES.times do
      360.days
    end
  end
  
  x.report("metaprogramming 360.weeks") do
    TIMES.times do    
      360.m_weeks
    end
  end
  
  x.report("no metaprogramming 360.weeks") do
    TIMES.times do
      360.weeks
    end
  end

  x.report("metaprogramming 18.months") do
    TIMES.times do    
      18.m_months
    end
  end
  
  x.report("no metaprogramming 18.months") do
    TIMES.times do
      18.months
    end
  end
  
  x.report("metaprogramming 7.years") do
    TIMES.times do    
      7.m_years
    end
  end
  
  x.report("no metaprogramming 7.years") do
    TIMES.times do
      7.years
    end
  end
  
end


 Rehearsal ------------------------------------------------------------------
metaprogramming 360.seconds      0.130000   0.000000   0.130000 (  0.133164)
no metaprogramming 360.hours     0.050000   0.000000   0.050000 (  0.042655)
metaprogramming 360.minutes      0.130000   0.000000   0.130000 (  0.133327)
no metaprogramming 360.minutes   0.040000   0.000000   0.040000 (  0.042401)
metaprogramming 360.hours        0.140000   0.000000   0.140000 (  0.134312)
no metaprogramming 360.hours     0.040000   0.000000   0.040000 (  0.043125)
metaprogramming 360.days         0.130000   0.000000   0.130000 (  0.134949)
no metaprogramming 360.days      0.050000   0.000000   0.050000 (  0.043745)
metaprogramming 360.weeks        0.130000   0.000000   0.130000 (  0.135581)
no metaprogramming 360.weeks     0.050000   0.000000   0.050000 (  0.043544)
metaprogramming 18.months        0.130000   0.000000   0.130000 (  0.135234)
no metaprogramming 18.months     0.050000   0.000000   0.050000 (  0.044354)
metaprogramming 7.years          0.140000   0.000000   0.140000 (  0.144062)
no metaprogramming 7.years       0.050000   0.000000   0.050000 (  0.044392)
--------------------------------------------------------- total: 1.260000sec

                                     user     system      total        real
metaprogramming 360.seconds      0.130000   0.000000   0.130000 (  0.132567)
no metaprogramming 360.hours     0.040000   0.000000   0.040000 (  0.042777)
metaprogramming 360.minutes      0.140000   0.000000   0.140000 (  0.132554)
no metaprogramming 360.minutes   0.040000   0.000000   0.040000 (  0.043193)
metaprogramming 360.hours        0.130000   0.000000   0.130000 (  0.133027)
no metaprogramming 360.hours     0.050000   0.000000   0.050000 (  0.042613)
metaprogramming 360.days         0.130000   0.000000   0.130000 (  0.138637)
no metaprogramming 360.days      0.050000   0.000000   0.050000 (  0.043213)
metaprogramming 360.weeks        0.130000   0.000000   0.130000 (  0.134049)
no metaprogramming 360.weeks     0.040000   0.000000   0.040000 (  0.043713)
metaprogramming 18.months        0.140000   0.000000   0.140000 (  0.134941)
no metaprogramming 18.months     0.040000   0.000000   0.040000 (  0.043980)
metaprogramming 7.years          0.150000   0.000000   0.150000 (  0.143389)
no metaprogramming 7.years       0.040000   0.000000   0.040000 (  0.044585)
 0.136591)

The metaprogramming version of the same implementation is almost 3 times slower!

Moral of the story: only use metaprogramming if you really have to or if you don't care about speed of execution.


more »

Avoid using metaprogramming (seriously!) »

Created at: 04.05.2008 11:29, source: Rails on the Run - Home, tagged: benchmark merb metaprogramming speed

Ruby is sexy, Ruby is cool and its metaprogramming potential offers some really cook features. However you might not realize that your cleverness is slowing down your code.

Today I was working on cleaning up merb_helper a Merb plugin that brings a lot of the stuff Rails developers are used to. In Merb we aim for speed and try to avoid magic.

merb_plugin didn't receive a lot of love from the main contributors but few features were added by different contributors and the code became hard to maintain.

Looking at the code I quickly found this bad boy:

(Old Merb Time DSL using metaprogramming)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21

   
  module MetaTimeDSL

    {:second => 1, 
     :minute => 60, 
     :hour => 3600, 
     :day => [24,:hours], 
     :week => [7,:days], 
     :month => [30,:days], 
     :year => [364.25, :days]}.each do |meth, amount|
      define_method "m_#{meth}" do
        amount = amount.is_a?(Array) ? amount[0].send(amount[1]) : amount
        self * amount
      end
      alias_method "m_#{meth}s".intern, "m_#{meth}"
    end

  end
  Numeric.send :include, MetaTimeDSL

The above code looks awful to me and I decided to rewrite it a way I thought would be more efficient:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41

  module TimeDSL

    def second
      self * 1
    end
    alias_method :seconds, :second

    def minute
      self * 60
    end
    alias_method :minutes, :minute

    def hour
      self * 3600
    end
    alias_method :hours, :hour

    def day
      self * 86400
    end
    alias_method :days, :day

    def week
      self * 604800
    end
    alias_method :weeks, :week

    def month
      self * 2592000
    end
    alias_method :months, :month

    def year
      self * 31471200
    end
    alias_method :years, :year

  end
  Numeric.send :include, TimeDSL

To make sure I was right, I run the following benchmarks:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127

require 'benchmark'
TIMES = (ARGV[0] || 100_000).to_i

Benchmark.bmbm do |x|
  
  x.report("metaprogramming 360.seconds") do
    TIMES.times do    
      360.m_seconds
    end
  end
  
  x.report("no metaprogramming 360.hours") do
    TIMES.times do
      360.seconds
    end
  end
  
  x.report("metaprogramming 360.minutes") do
    TIMES.times do    
      360.m_minutes
    end
  end
  
  x.report("no metaprogramming 360.minutes") do
    TIMES.times do
      360.minutes
    end
  end
  
  x.report("metaprogramming 360.hours") do
    TIMES.times do    
      360.m_hours
    end
  end
  
  x.report("no metaprogramming 360.hours") do
    TIMES.times do
      360.hours
    end
  end
  
  x.report("metaprogramming 360.days") do
    TIMES.times do    
      360.m_days
    end
  end
  
  x.report("no metaprogramming 360.days") do
    TIMES.times do
      360.days
    end
  end
  
  x.report("metaprogramming 360.weeks") do
    TIMES.times do    
      360.m_weeks
    end
  end
  
  x.report("no metaprogramming 360.weeks") do
    TIMES.times do
      360.weeks
    end
  end

  x.report("metaprogramming 18.months") do
    TIMES.times do    
      18.m_months
    end
  end
  
  x.report("no metaprogramming 18.months") do
    TIMES.times do
      18.months
    end
  end
  
  x.report("metaprogramming 7.years") do
    TIMES.times do    
      7.m_years
    end
  end
  
  x.report("no metaprogramming 7.years") do
    TIMES.times do
      7.years
    end
  end
  
end


 Rehearsal ------------------------------------------------------------------
metaprogramming 360.seconds      0.130000   0.000000   0.130000 (  0.133164)
no metaprogramming 360.hours     0.050000   0.000000   0.050000 (  0.042655)
metaprogramming 360.minutes      0.130000   0.000000   0.130000 (  0.133327)
no metaprogramming 360.minutes   0.040000   0.000000   0.040000 (  0.042401)
metaprogramming 360.hours        0.140000   0.000000   0.140000 (  0.134312)
no metaprogramming 360.hours     0.040000   0.000000   0.040000 (  0.043125)
metaprogramming 360.days         0.130000   0.000000   0.130000 (  0.134949)
no metaprogramming 360.days      0.050000   0.000000   0.050000 (  0.043745)
metaprogramming 360.weeks        0.130000   0.000000   0.130000 (  0.135581)
no metaprogramming 360.weeks     0.050000   0.000000   0.050000 (  0.043544)
metaprogramming 18.months        0.130000   0.000000   0.130000 (  0.135234)
no metaprogramming 18.months     0.050000   0.000000   0.050000 (  0.044354)
metaprogramming 7.years          0.140000   0.000000   0.140000 (  0.144062)
no metaprogramming 7.years       0.050000   0.000000   0.050000 (  0.044392)
--------------------------------------------------------- total: 1.260000sec

                                     user     system      total        real
metaprogramming 360.seconds      0.130000   0.000000   0.130000 (  0.132567)
no metaprogramming 360.hours     0.040000   0.000000   0.040000 (  0.042777)
metaprogramming 360.minutes      0.140000   0.000000   0.140000 (  0.132554)
no metaprogramming 360.minutes   0.040000   0.000000   0.040000 (  0.043193)
metaprogramming 360.hours        0.130000   0.000000   0.130000 (  0.133027)
no metaprogramming 360.hours     0.050000   0.000000   0.050000 (  0.042613)
metaprogramming 360.days         0.130000   0.000000   0.130000 (  0.138637)
no metaprogramming 360.days      0.050000   0.000000   0.050000 (  0.043213)
metaprogramming 360.weeks        0.130000   0.000000   0.130000 (  0.134049)
no metaprogramming 360.weeks     0.040000   0.000000   0.040000 (  0.043713)
metaprogramming 18.months        0.140000   0.000000   0.140000 (  0.134941)
no metaprogramming 18.months     0.040000   0.000000   0.040000 (  0.043980)
metaprogramming 7.years          0.150000   0.000000   0.150000 (  0.143389)
no metaprogramming 7.years       0.040000   0.000000   0.040000 (  0.044585)
 0.136591)

The metaprogramming version of the same implementation is almost 3 times slower!

Moral of the story: only use metaprogramming if you really have to or if you don't care about speed of execution.


more »