Marty Andrews

artful code

Tuesday, October 25, 2011

A ruby spec profiling story

I've always used ruby-prof in the past to profile my Ruby code, but a colleague yesterday put me on to the Google perftools for Ruby code. A bit of research turned up some interesting things.

According to http://blog.pluron.com/2008/01/ruby-on-rails-i.html,
ruby-prof attributes full cost of garbage collection to the method where GC gets triggered, not the methods that allocate the memory

That was news to me. I tried running the profiler over an app I'm working on, and got this:

Total: 23530 samples
13244 56.3% 56.3% 13244 56.3% garbage_collector
4223 17.9% 74.2% 4331 18.4% ActiveRecord::ConnectionAdapters::Mysql2Adapter#execute
678 2.9% 77.1% 678 2.9% ActiveRecord::ConnectionAdapters::Mysql2Adapter#active?
402 1.7% 78.8% 403 1.7% MonitorMixin::ConditionVariable#signal
258 1.1% 79.9% 294 1.2% Method#call

Wow! That's a massive amount of time in GC! What can I do about that?

That lead me to an article by Jamis Buck at http://37signals.com/svn/posts/2742-the-road-to-faster-tests. It describes a way to address GC issues for Test::Unit, but there's a nice rspec version at https://gist.github.com/790118. I applied that to my code and ran it again. The new profile was:

Total: 11331 samples
3730 32.9% 32.9% 3804 33.6% ActiveRecord::ConnectionAdapters::Mysql2Adapter#execute
2021 17.8% 50.8% 2021 17.8% garbage_collector
720 6.4% 57.1% 720 6.4% ActiveRecord::ConnectionAdapters::Mysql2Adapter#active?
376 3.3% 60.4% 376 3.3% MonitorMixin::ConditionVariable#signal
352 3.1% 63.5% 353 3.1% Object#reconsider_gc_deferment

My spec build time also cam down from 375 seconds to 238 seconds. That's a massive improvement.

The post form Jamis also mentions cleaning up some instance variables, which I'll try amongst some further tweaking, but that improvement was significant enough that I figured it might point someone else in the right direction too.

2 comments:

  1. The same profiling efforts on said colleague's machine showed a GC time of ~4%. Curiously, the GC optimisation still yielded a 23% reduction in rake spec execution time. Is perftools telling fibs?

    ReplyDelete
  2. Vì sao lại có quan ngại “thuốc Fucoidan có tốt không” ?
    Như kể trên, chúng ta thấy Fucoidan có rất nhiều tác dụng tốt. Tác dụng của thuốc Fucoidan http://mayduavong.me/tag/cong-dung-cua-thuoc-fucoidan-tri-ung-thu-cua-my Với nguồn gốc tự nhiên, chắc chắn giá thành của nó sẽ cao hơn các loại thuốc hóa học khác. Chính bởi lý do này đã khiến những người xấu lợi dụng để trục lợi cho bản thân. Nơi nào bán thuốc Fucoidan http://thuocbomat.net/tag/thuoc-fucoidan-ban-o-dau .Họ tận dụng đặc điểm tốt cho sức khỏe, được nhiều người sử dụng của Fucoidan, sau đó làm giả Fucoidan chất lượng kém, số tiền bỏ ra để chế xuất rất nhỏ và bán ra với giá thành bằng giá của Fucoidan thật trên thị trường. Thành phần thuốc Fucoidan http://thuocgiaidocgan.net/tag/fucoidan-gia-re. Nhiều người tiêu dùng do quá nhẹ dạ cả tin đã mua phải loại Fucoidan giả, nên khi sử dụng sẽ không thấy được những tác dụng tốt của nó. Thực phẩm chức năng hỗ trợ trị ung thư thuốc fucoidan http://nammongtay.com/tags/thuc-pham-chuc-nang-fucoidan. Thậm chí, một số loại Fucoidan giả còn đem đến ảnh hưởng xấu cho sức khỏe. Đây chính là lý do lý giải vì sao lại có thắc mắc về chất lượng của Fucoidan. Một lời khuyên dành cho người tiêu dùng là nên tìm các cơ sở kinh doanh uy tín để mua loại thuốc bổ dưỡng này.

    ReplyDelete