Conflicting performance results

Rails
1

Hi,

this is a simplfied version of my controller code:

def get_item_types_for_brand
selected_brand = Brand.find(params[:brand][:id])
render(:text => ‘random string’, :layout => false)
end

It is taking way too much time to execute and when I looked at the log
file (in dev), I see this:

Processing CategoryController#get_item_types_for_brand (for 127.0.0.1 at
2006-12-23 16:39:25) [POST]
Session ID: 3200e229ed5425da68928d0e50085fb3
Parameters: {“brand”=>{“id”=>“2”},
“action”=>“get_item_types_for_brand”, “controller”=>“category”}
e[4;35;1mBrand Columns (0.000378)e[0m e[0mSHOW FIELDS FROM
brandse[0m
e[4;36;1mBrand Load (0.000415)e[0m e[0;1mSELECT * FROM brands WHERE
(brands.id = 2) e[0m
Completed in 0.03451 (28 reqs/sec) | Rendering: 0.00016 (0%) | DB:
0.00079 (2%) | 200 OK
[http://localhost/category/get_item_types_for_brand]

I dont understand why it says that the query is executed in 0.000415 of
a second but it is completed in 0.03451 of a second.

What can explain this?

Thanks for your suggestion on how to solve this or at least some
explanation or leads.

2

On Dec 23, 2006, at 1:46 PM, Alain wrote:

It is taking way too much time to execute and when I looked at the log
[4;36;1mBrand Load (0.000415) [0m [0;1mSELECT * FROM brands WHERE
What can explain this?

Thanks for your suggestion on how to solve this or at least some
explanation or leads.

Alain-

The performance metrics in the rails logs are not accurate at all.

It is really hard to have a system reliably measure its own
performance. The logs lie. Use httperf or ab to do any kind of req/
sec testing.

Cheers-
– Ezra Z.
– Lead Rails Evangelist
– [email protected]
– Engine Y., Serious Rails Hosting
– (866) 518-YARD (9273)