While working on benchmarking bugfreak’s api on the newly release rubinius 2.0 I’ve stumbled upon a interesting bottleneck, will resume the rubinius test in the next blog post in the mean time check this out.
A simple grape end point
module Apibugfreak | |
class Resources::V1::ErrorsAPI < Grape::API | |
resources :errors do | |
desc 'Create a error' | |
post do | |
authenticate! | |
ApplicationErrorService.new(@current_application).create_application_error(params) | |
end | |
end | |
end | |
end |
The ApplicationErrorService will use the following finder to fetch the user application it needs to create errors on:
module UserFinders | |
extend ActiveSupport::Concern | |
def find_user_application(token) | |
user_applications.find(token) | |
end | |
end |
The UserApplication is a mongoid model:
class UserApplication | |
include Mongoid::Document | |
include Mongoid::Timestamps | |
include ApplicationErrorBuilder | |
include UserApplicationFinders | |
field :name, type: String, default: '' | |
embeds_many :application_errors | |
belongs_to :user | |
index 'user_id' => 1 | |
validates_presence_of :name | |
end |
Notice it embeds many application errors.
Will do 1024 posts on this end point 16 at the time using ab – Apache HTTP server benchmarking tool
ab -p tests/errors.txt -T application/x-www-form-urlencoded -H "Token: token" -H "Api-Key: api-key" -e tests/errors_mri_result.csv -n 1024 -c 16 http://localhost:3000/v1/api/errors/ |
On the first run after adding 1024 errors to an application the results are pretty good for my Dell laptop with a I7 and a SSD running elementary (a spin of ubuntu 12.04):
Concurrency Level: 16 | |
Time taken for tests: 23.776 seconds | |
Complete requests: 1024 | |
Failed requests: 0 | |
Write errors: 0 | |
Total transferred: 583680 bytes | |
Total POSTed: 366592 | |
HTML transferred: 246784 bytes | |
Requests per second: 43.07 [#/sec] (mean) | |
Time per request: 371.504 [ms] (mean) | |
Time per request: 23.219 [ms] (mean, across all concurrent requests) | |
Transfer rate: 23.97 [Kbytes/sec] received | |
15.06 kb/s sent | |
39.03 kb/s total |
Running the exact command a second time will give worse results increasing the time taken by 5 times:
Concurrency Level: 16 | |
Time taken for tests: 111.600 seconds | |
Complete requests: 1024 | |
Failed requests: 0 | |
Write errors: 0 | |
Total transferred: 583680 bytes | |
Total POSTed: 366592 | |
HTML transferred: 246784 bytes | |
Requests per second: 9.18 [#/sec] (mean) | |
Time per request: 1743.743 [ms] (mean) | |
Time per request: 108.984 [ms] (mean, across all concurrent requests) | |
Transfer rate: 5.11 [Kbytes/sec] received | |
3.21 kb/s sent | |
8.32 kb/s total |
Ok, maybe the problem is that I was writing this blog post in the same time and my browser was eating valuable CPU cycles. Unfortunately it gets worse again:
Concurrency Level: 16 | |
Time taken for tests: 186.323 seconds | |
Complete requests: 1024 | |
Failed requests: 0 | |
Write errors: 0 | |
Total transferred: 583680 bytes | |
Total POSTed: 366592 | |
HTML transferred: 246784 bytes | |
Requests per second: 5.50 [#/sec] (mean) | |
Time per request: 2911.298 [ms] (mean) | |
Time per request: 181.956 [ms] (mean, across all concurrent requests) | |
Transfer rate: 3.06 [Kbytes/sec] received | |
1.92 kb/s sent | |
4.98 kb/s total |
I did a couple of other tests and the time taken to run them got higher and higher.
The code that was run was pretty simple so I figured that the issue must be the increasing number of embedded documents. Indeed mongoid when fetching a document that has many embedded documents will also fetch all it’s embedded documents and create ruby objects out of them. To fix the performance issue just instruct mongoid not to fetch the embedded document collection, this will not influence the ability to add to the collection, we can do this with the very usefull function “without”.
The new finder module:
module UserFinders | |
extend ActiveSupport::Concern | |
def find_user_application(token) | |
user_applications.without(:application_errors).find(token) | |
end | |
end |
And it will run consistently between consecutive runs.