4

私は大規模なRailsアプリを持っており、(ひどい)パフォーマンスを改善したいと考えています.

ruby-prof で実行してもあまり役に立ちません。次のような出力が得られます (シンのプロダクション モードで実行):

Thread ID: 9322800
Total: 1.607768
Sort by: self_time

 %self     total     self     wait    child    calls   name
 26.03      0.42     0.42     0.00     0.00     1657   Module#define_method 
  8.03      0.13     0.13     0.00     0.00      267   Set#initialize 
  4.41      0.07     0.07     0.00     0.00       44   PG::Result#values 
  4.28      0.07     0.07     0.00     0.00     1926   ActiveSupport::Callbacks::Callback#start 
  4.21      0.07     0.07     0.00     0.00    14835   Kernel#hash 
  4.13      0.08     0.07     0.00     0.01      469   Module#redefine_method 
  4.11      0.07     0.07     0.00     0.00       63  *<Class::ActiveRecord::Base>#with_scope 
  4.02      0.07     0.06     0.00     0.00      774   ActiveSupport::Callbacks::Callback#_compile_options 
  3.24      0.05     0.05     0.00     0.00       30   PG::Connection#async_exec 
  2.31      0.40     0.04     0.00     0.37     2130  *Module#class_eval 
  1.47      0.02     0.02     0.00     0.00        6   PG::Connection#unescape_bytea 
  1.03      0.05     0.02     0.00     0.03      390  *Array#select 

* indicates recursively called methods

ガベージ コレクターで多くの時間を費やしているのではないかと推測したので、REEで実行しているので、GC.enable_stats を使用して詳細情報を取得することにしました。アプリケーションコントローラーに以下を追加しました。

around_filter :enable_gc_stats

private

def enable_gc_stats
  GC.enable_stats

  begin
    yield
  ensure
    GC.disable_stats
    GC.clear_stats
  end
end

REE とシン Web サーバー (少し遅くなるので ruby​​-prof が無効になっている) を使用して、私のマシンで本番モードで実行されている比較的大きなページで、次のようになります。

Completed 200 OK in 1093ms (Views: 743.1ms | ActiveRecord: 139.2ms)

GC.collections: 11
GC.time: 666299 us 666.299 ms
GC.growth: 461 KB

GC.allocated_size: 152 MB
GC.num_allocations: 1,924,773
ObjectSpace.live_objects: 1,015,195
ObjectSpace.allocated_objects: 12,393,644

したがって、1093 ミリ秒かかったページの場合、ほぼ 700 ミリ秒がガベージ コレクターで費やされたように見えます。誰もこの種の問題を以前に経験したことがありますか? 特に私のアプリについてはお役に立てないことは承知しております (多くの宝石や物が含まれている非常に大きなアプリです)。しかし、なぜこんなに多くのゴミが作成されているのかをよりよく理解するためのテクニックやツールはありますか?

どんなアイデアでも大歓迎です!

4

1 に答える 1

6

Railsログには、ほとんどの時間(75%)がビューコードに費やされていることが示されています。

プロファイルレポートにはModule#define_method、セルフタイム、Module#class_eval合計時間、およびの3つの明らかなホットスポットが表示されSet#initializeます。

define_methodそしてclass_eval、私には過剰に思える動的なコード実行がたくさんある可能性があることを示します。通常、コードを繰り返し再生成するのではなく、早期に生成して再利用する必要があります。これは、ほぼ確実に、過度のオブジェクト割り当ての問題の一部です。フラットレポートの代わりにグラフレポートを作成すると、これらの高価なパスに分類される親メソッドを見つけるのに役立ち、最適化できる場所へのポインタが得られる可能性があります。

Set#initializeコードが実行する必要があることの実際のアーティファクトである場合もあれば、一度実行して再利用のために定数またはインスタンス/クラス変数に割り当てることができる重要なSet[...]またはセットの作成呼び出しがインラインにあることの兆候である場合もあります。Set::new

ruby-profは問題ありませんが、 rack-perftools_profilerを使用してラックレールに簡単に接続できるperftools.rbも試してみることをお勧めします。perftoolsには、ホット実行パスをはるかに簡単に理解できるようにする拡張された視覚化ツールがいくつかあります。

REEを実行していて、広範なオブジェクト割り当て(したがってガベージコレクション)が問題になるため、memprofを試して、これらすべての割り当てが何からどこから来ているのかについての洞察を得ることができます。

割り当てられるオブジェクトの量を減らす方法が見つからない場合は、GCを調整して、通常の要求の割り当て要求を保持するのに十分な大きさのヒープを事前に割り当てることで、プロセスメモリサイズを大きくしてGCの負担を軽減できます。Unicornは、帯域外GC用のラックモジュールを提供しています。このモジュールのアプローチをthinで動作するように適応させ、すべてのGC時間をリクエスト間で移動できる場合があります。CPUコストは引き続き支払われますが、少なくともガベージコレクションの応答が遅れることはありません。

于 2013-01-21T00:16:36.187 に答える