Tuesday, July 10, 2012

Grails 2.1.0 performance

In this installment we'll be checking out the performance of the latest (2.1.0) version of Grails compared to 1.3.9 and 2.0.4. So without further due let's jump right into the code.

The HomeController
class HomeController {
  def index() {
    def date = new Date()
    redirect uri: date.format("/yyyy/MM")
  }

  def page() {
    def months = [ '', 'January', 'February', 'March', 'April', 'May', 'June', 
      'July', 'August', 'September', 'October', 'November', 'December' ]
    [ year: params?.year, month: params?.month, months: months ]
  }
}

So we see 2 actions here: one that checks the current date and does a redirect and one that spits out some data to view. So let's see the view then :)

The page.gsp:
<!doctype html>
<html>

<head>
  <title>Galery</title>
</head>

<body>
  <ul>
    <g:each in="${1..12}" var="i">
    <li class="${i == month ? 'current' : ''}"><a href="/${year}/${i}">${months[i]}</a></li>
    </g:each>
  </ul>
</body>

And now - time for benchmark results. All applications started this way:

grails prod run-war

and benchmarked using Apache Benchmark like this:

ab -n 1000 -c 10 http://localhost:8080/example/2012/03 up until the point when the figures became stable (usually between 20-30 executions with 5-10 seconds breaks in between).

Grails 1.3.9

Server Software:        Apache-Coyote/1.1
Server Hostname:        localhost
Server Port:            8080

Document Path:          /example139/2012/03
Document Length:        776 bytes

Concurrency Level:      10
Time taken for tests:   0.526 seconds
Complete requests:      1000
Failed requests:        0
Write errors:           0
Total transferred:      942000 bytes
HTML transferred:       776000 bytes
Requests per second:    1902.84 [#/sec] (mean)
Time per request:       5.255 [ms] (mean)
Time per request:       0.526 [ms] (mean, across all concurrent requests)
Transfer rate:          1750.47 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.1      0       2
Processing:     1    5   3.5      4      41
Waiting:        1    5   3.5      4      41
Total:          1    5   3.6      4      41

Percentage of the requests served within a certain time (ms)
  50%      4
  66%      6
  75%      6
  80%      7
  90%     10
  95%     12
  98%     14
  99%     17
 100%     41 (longest request)

Grails 2.0.4

Server Software:        Apache-Coyote/1.1
Server Hostname:        localhost
Server Port:            8080

Document Path:          /example204/2012/03
Document Length:        776 bytes

Concurrency Level:      10
Time taken for tests:   0.235 seconds
Complete requests:      1000
Failed requests:        0
Write errors:           0
Total transferred:      942000 bytes
HTML transferred:       776000 bytes
Requests per second:    4254.25 [#/sec] (mean)
Time per request:       2.351 [ms] (mean)
Time per request:       0.235 [ms] (mean, across all concurrent requests)
Transfer rate:          3913.58 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.3      0       5
Processing:     1    2   1.5      2      16
Waiting:        0    2   1.5      2      16
Total:          1    2   1.6      2      16

Percentage of the requests served within a certain time (ms)
  50%      2
  66%      2
  75%      3
  80%      3
  90%      4
  95%      5
  98%      7
  99%     10
 100%     16 (longest request)

As we can see there's quite a performance gain between 1.3.9 and 2.0.4. Good!

Grails 2.1.0

Server Software:        Apache-Coyote/1.1
Server Hostname:        localhost
Server Port:            8080

Document Path:          /example/2012/03
Document Length:        776 bytes

Concurrency Level:      10
Time taken for tests:   0.333 seconds
Complete requests:      1000
Failed requests:        0
Write errors:           0
Total transferred:      942000 bytes
HTML transferred:       776000 bytes
Requests per second:    3002.16 [#/sec] (mean)
Time per request:       3.331 [ms] (mean)
Time per request:       0.333 [ms] (mean, across all concurrent requests)
Transfer rate:          2761.76 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.2      0       3
Processing:     1    3   3.0      2      29
Waiting:        0    3   2.9      2      29
Total:          1    3   3.0      2      29

Percentage of the requests served within a certain time (ms)
  50%      2
  66%      3
  75%      4
  80%      4
  90%      6
  95%      9
  98%     12
  99%     17
 100%     29 (longest request)

It looks like 2.1.0 is a little bit (actually 1/4th) slower in this case than 2.0.4. Interesting...

Rails 3.2.6


For comparison I've done a similar experiment translating the the same routing, controller and view to Rails (just out of curiosity).

We'll start the application under Unicorn with 4 workers (that's how many cores my notebook has)

unicorn -E production -p 9393 -c config.rb

And the config.rb
worker_processes 4

Server Software:        
Server Hostname:        localhost
Server Port:            9393

Document Path:          /2012/03
Document Length:        728 bytes

Concurrency Level:      10
Time taken for tests:   1.109 seconds
Complete requests:      1000
Failed requests:        0
Write errors:           0
Non-2xx responses:      1000
Total transferred:      983000 bytes
HTML transferred:       728000 bytes
Requests per second:    901.84 [#/sec] (mean)
Time per request:       11.088 [ms] (mean)
Time per request:       1.109 [ms] (mean, across all concurrent requests)
Transfer rate:          865.73 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.0      0       0
Processing:     6   11   5.9     10      64
Waiting:        6   11   5.9     10      64
Total:          7   11   5.9     10      64

Percentage of the requests served within a certain time (ms)
  50%     10
  66%     11
  75%     11
  80%     12
  90%     14
  95%     15
  98%     19
  99%     55
 100%     64 (longest request)

Sinatra


Now let's take a look at how a similar case will handle a Ruby framework, Sinatra.
require 'rubygems'
require 'sinatra'
require 'slim'

disable :logging

get '/' do
  date = Time.now
  redirect "/#{date.year}/#{date.month}"
end

get '/:year/:month' do
  @current = Time.new(params[:year], params[:month])
  @months  = [ '', 'January', 'February', 'March', 'April', 'May', 'June', 'July', 'August', 'September', 'October', 'November', 'December' ]
  slim :index
end

__END__

@@ index
doctype html
html
  head
    title Galery
  body
    ul 
      - (1..12).each do |month|
        li class="#{@current.month == month ? "month current" : "month"}"
          a href="/#{@current.year}/#{month}" #{@months[month]}

We're using sinatra with slim templating engine (my favorite!). We'll start the application the same way as the Rails app above.

Now for the actual results:
Server Software:        
Server Hostname:        localhost
Server Port:            9393

Document Path:          /2012/03
Document Length:        709 bytes

Concurrency Level:      10
Time taken for tests:   0.449 seconds
Complete requests:      1000
Failed requests:        0
Write errors:           0
Total transferred:      922000 bytes
HTML transferred:       709000 bytes
Requests per second:    2227.71 [#/sec] (mean)
Time per request:       4.489 [ms] (mean)
Time per request:       0.449 [ms] (mean, across all concurrent requests)
Transfer rate:          2005.81 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.1      0       1
Processing:     1    4   2.8      4      29
Waiting:        0    4   2.8      4      29
Total:          1    4   2.8      4      29

Percentage of the requests served within a certain time (ms)
  50%      4
  66%      4
  75%      5
  80%      5
  90%      6
  95%      7
  98%     12
  99%     22
 100%     29 (longest request)

Ok, now you can really see the difference in count of bytes sent over the wire. That's due to the differences in view technology (slim is very compact in the actual output)

At the end of the day the performance of both Grails and Sinatra (even though not very comparable) is similar with a clear performance winner :) Rails lacks a bit in performance.

There is however a difference in startup time and memory usage:

FrameworkMemoryStartup time
Grails 1.3.9485.1MB21.95s user 0.76s system 109% cpu 20.656 total
Grails 2.0.4699.3MB53.51s user 1.38s system 152% cpu 35.942 total
Grails 2.1.0713.1MB30.19s user 1.30s system 106% cpu 29.609 total
Rails 3.2.6169.8MB9.64s user 0.68s system 259% cpu 3.977 total
Sinatra on Unicorn82.1MB1.46s user 0.18s system 55% cpu 2.963 total

Have fun!

1 comment:

Alexandre Daigre said...

You can increase the number of workers above your CPU threads numbers.

Unicorn doesn't multithreaded/async and blocking IO block the process.