Railsプロセスのメモリ漏洩を監視するテクニック


Rails応用は比較的に遭遇しやすい2種類の性能問題:1種類はRailsの実行が遅く、CPUの消費が高すぎる.もう1つはRailsプロセスのメモリ漏洩です.この2つの問題を解決するには、まず問題が発生したコードを正確に特定してから、どのように薬を処方するかを知る必要があります.
一、Railsプロセスの実行性能をどのように監視するか
位置決めはCPUを消費し、実行速度が遅いRailsコードは、かなり簡単なことで、productionだけが必要です.logは統計分析をして、実行時間が最も長い要求を抽出して、問題が明らかになった.productionのためlogはRails要求の実行時間を詳細に統計した.例えば:
Completed in 0.00693 (144 reqs/sec) | Rendering: 0.00489 (70%) | DB: 0.00000 (0%) | 200 OK [http://www.iteye.com/]
Completed in 0.17238 (5 reqs/sec) | Rendering: 0.10011 (58%) | DB: 0.06244 (36%) | 200 OK [http://www.iteye.com/topic/49441?page=7]
Completed in 0.20508 (4 reqs/sec) | Rendering: 0.19373 (94%) | DB: 0.00645 (3%) | 200 OK [http://www.iteye.com/news/1586]

だからshellコマンドを1行書くだけで終わります!彼は最も時間がかかる500個の要求をフィルタしてtimingに保存した.ロゴの中.
grep "200 OK" production.log | awk '{print "ALL: " $3 "  View: " $8 " DB: " $12 "  URL: " $17 }' \
| sort -r | head -n 500 > timing.log

ソートされた結果は、次のようになります.
ALL: 5.51774  View: 5.38277 DB: 0.13338  URL: [http://www.iteye.com/wiki/topic/131966]
ALL: 5.51316  View: 5.31300 DB: 0.19400  URL: [http://www.iteye.com/wiki/topic/145383]
ALL: 5.51311  View: 5.39321 DB: 0.11234  URL: [http://www.iteye.com/wiki/topic/160370]
ALL: 5.51135  View: 5.37604 DB: 0.12652  URL: [http://www.iteye.com/wiki/topic/233365]
ALL: 5.49881  View: 5.35998 DB: 0.10637  URL: [http://www.iteye.com/wiki/topic/265217]

どのリクエストの実行が遅いかは、一目瞭然です.もちろん、リアルタイムで監視することもできます.
Railsが現在実行中のリクエストURLをtopモニタウィンドウに表示 .
二、Railsプロセスのメモリ漏れをどのように監視するか
CPUを監視することは容易なことであるが、Railsプロセスのメモリ漏洩を監視することは、productionのため非常に困難である.logにはプロセスのメモリの変化状況は記録されておらず、ruby APIがプロセスで使用されている物理メモリを直接クエリーするために使用できるものは見つかりません.実際、1つのプロセスの物理メモリを取得するのはプラットフォーム関連の操作であり、各オペレーティングシステムは独自のAPIを持っており、汎用的ではなく、C言語を使用して符号化することも容易ではありません.
しかし、Linuxオペレーティングシステムでは、プロセスのメモリ状況を取得する近道があります.Linuxの/procファイルシステムはカーネルのイメージであり、/proc/プロセスpid/statusファイルはこのプロセスのステータス情報を記録します.たとえば、次のようにします.
Name:   dispatch.fcgi
State:  S (sleeping)
SleepAVG:       135%
Tgid:   26645
Pid:    26645
PPid:   1
TracerPid:      0
Uid:    1002    1002    1002    1002
Gid:    100     100     100     100
FDSize: 64
Groups: 14 16 17 33 100 
VmSize:   245680 kB
VmLck:         0 kB
VmRSS:    209104 kB
VmData:   205116 kB
VmStk:       824 kB
VmExe:       764 kB
VmLib:      4220 kB
Threads:        1
SigPnd: 0000000000000000
ShdPnd: 0000000000000000
SigBlk: 0000000000000000
SigIgn: 0000000000001000
SigCgt: 0000000002006e47
CapInh: 0000000000000000
CapPrm: 0000000000000000
CapEff: 0000000000000000

注意14行目のVmRSSには、プロセスが実際に使用している物理メモリ(Residence)が記録されています.これがプロセスが実際に使用している物理メモリです.したがって、ファイルの14行目を読み込むと、メモリ情報が得られます.
そこで我々の任務は、Railsが要求を処理する前にメモリを記録し、Railsが要求を処理した後、メモリを記録し、メモリの変化状況を計算し、productionに書き込むことになった.ロゴの中へ行きます.この作業を完了するには、Railsアプリケーションのapp/controllers/applicationだけが必要です.rbにはいくつかのコードが追加されています.

  around_filter :record_memory
  def record_memory
    process_status = File.open("/proc/#{Process.pid}/status")
    13.times { process_status.gets }
    rss_before_action = process_status.gets.split[1].to_i
    process_status.close
    yield
    process_status = File.open("/proc/#{Process.pid}/status")
    13.times { process_status.gets }
    rss_after_action = process_status.gets.split[1].to_i
    process_status.close
    logger.info("CONSUME MEMORY: #{rss_after_action - rss_before_action} \
KB\tNow: #{rss_after_action} KB\t#{request.url}")
  end

処理要求の前後のメモリの変化を記録するAroundFilterを定義した.この情報があれば、私たちの次のことは簡単です.productionからだけです.logの中からこの行のlogを抽出して、統計分析をすればいいです.これも1行のshellだけでいいです.
grep "CONSUME MEMORY" production.log | grep -v "CONSUME MEMORY: 0" |  \
 grep -v "CONSUME MEMORY: -" |  awk '{print $3 "\t" $6 "\t" $8 }' | sort -r -n | \
 head -n 500 > memory.log 

メモリ記録を抽出する、メモリが増加していないことを除去し、メモリ減少(GCが発生した)の要求を除去し、それらの処理要求後にメモリが上昇する記録をソートし、上位500件の記録をmemoryに保存する.ロゴには、次のような結果が表示されます.

              URL
-----------------------------------------------
9528  175264  http://www.iteye.com/topic/304594
9524  129512  http://knityster.iteye.com/blog/172990
9496  147544  http://www.iteye.com/forums/
9492  197800  http://duyiwuer.iteye.com/rss
9452  146668  http://www.iteye.com/forums
9452  133844  http://wildlife.iteye.com/blog/47693
9440  157824  http://www.iteye.com/rss/blogs
9424  204664  http://www.iteye.com/wiki/topic/251964
9384  142200  http://towerhe.iteye.com/blog/93704
9380  165372  http://www.iteye.com/wiki/topic/77434
9368  207460  http://superleo.iteye.com/rss

第1列は1つの要求にアクセスした後で、Railsプロセスのメモリは9 MB余り上昇して、第2列は要求を処理し終わって、Railsプロセスは現在実際に170 MB余りのメモリを占めて、第3列はどんな要求を処理しました.
この統計結果によると、Railsプロセスのメモリ漏洩の原因を簡単に見つけることができます.Railsプロセスにアクセスするとメモリが急増するのは簡単ではありません.これは簡単ではありませんか.実際、この方法でJavaEyeは30分以上しかかからず、半年以上も悩んでいたメモリ漏れの問題を解決しました.方法は土ですが、効果的です.