操作
バグ #925
未完了
mikutterがメモリを大量に消費することがある
プラグイン名:
ブランチ:
クラッシュする:
説明
いわゆるダークマターです。
https://github.com/toshia/memory_profiler/ を入れて1日半程度起動しっぱなしにしておいたmikutter(e1b61877)でグラフを生成したところ、次のグラフが得られました。
この時点でVIRTが20,844,868KB, RESが18,716,708KBとなっています。
GC.start; File.open('/tmp/strings.txt', 'w'){|f| f.puts(ObjectSpace.each_object(String).to_a)}をmikutterコンソールで実行し、生き残っているStringのリストを得る$ cat /tmp/strings.txt | sort | uniq -c | sort -k1 -r | head -n30でダブリ個数の上位30件を取ってくる
以下はその結果です。どうもcairoに渡している色コード（詳細不明）と、画像関係っぽい文字列が異常に多く生き残っているようです。
40392 ja 31135 fit 19951 000000 16739 C0DEED 15604 https 15599 twitter.com 14341 333333 14159 Tokyo 12637 none 10775 10378 crop 10191 DDEEF6 10129 photo 9794 https://abs.twimg.com/images/themes/theme1/bg.png 9794 http://abs.twimg.com/images/themes/theme1/bg.png 8553 low 6356 FFFFFF 6162 0084B4 4896 recent 4741 njslyr 4515 /home/osak/app/mikutter/core/lib/uithreadonly.rb:23:in `block (2 levels) in singleton class' 3915 /search 3076 1DA1F2 2899 <a href="http://twitter.com" rel="nofollow">Twitter Web Client</a> 2880 en 2871 http 2846 pbs.twimg.com 2780 #njslyr 2680 mikutter.rb:92:in `<main>' 2679 mikutter.rb:63:in `boot!'この時点でのオブジェクト数のうち、メモリやオブジェクトの使用量に相関していそうなものの値は以下の通りでした。
>>> GC.start;ObjectSpace.each_object(Message).count
12605
>>> GC.start;ObjectSpace.each_object(User).reject{|u| Message::MessageUser === u}.count
7738
>>> GC.start;ObjectSpace.each_object(Gtk::TimeLine).reject{|t| t.destroyed?}.count
113
>>> GC.start;ObjectSpace.each_object(Gtk::TimeLine).reject{|t| t.destroyed?}.map(&:size).sort.reverse
[3959, 1243, 1041, 383, 206, 200, 200, 200, 200, 187, 182, 119, 117, 108, 97, 84, 76, 73, 60, 60, 59, 59, 58, 56, 52, 51, 44, 41, 41, 40, 40, 39, 38, 37, 35, 35, 34, 34, 29, 28, 27, 27, 27, 27, 25, 24, 24, 23, 23, 23, 22, 22, 21, 21, 20, 20, 14, 13, 12, 10, 8, 8, 7, 6, 5, 5, 5, 5, 4, 3, 3, 3, 2, 2, 2, 2, 2, 2, 1, 1, 1, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]
>>> GC.start;ObjectSpace.each_object(Hash).map(&:size).sort.reverse[0..30]
[41108, 27682, 12673, 7760, 7757, 5096, 4233, 4010, 1620, 1270, 1041, 1017, 918, 811, 498, 485, 436, 383, 383, 379, 373, 373, 348, 327, 327, 310, 291, 273, 262, 256, 253]
>>> GC.start;ObjectSpace.each_object(Gdk::Pixbuf).count
3905
>>> require 'objspace'
GC.start;ObjectSpace.memsize_of_all(String)
164113887
>>> require 'objspace'
GC.start;ObjectSpace.memsize_of_all(Array)
15699400
>>> require 'objspace'
GC.start;ObjectSpace.memsize_of_all(Hash)
159073600
あと入ってるプラグイン一覧：
YUKI.N@aincrad> ls ~/.mikutter/plugin display_requirements/ memory_profiler/ osa_k_store/ sub_parts_client/ dummy_dep/ mikustore/ pakuri/ toshi_a_store/ eject/ mikutter-fb/ penguin2716_store/ usercomplete/ favorited_count/ mikutter-subparts-image/ protected_source/ userutil/ geocode/ mikutter_shell_post/ randnum/ yukkuri_/ intelligent_fav/ mikutter_update_with_media_/ sakuratrick/ matsuyatter/ mikutter_yodobashi/ shindanmaker/ md5tweet/ nonomura/ show_tweet/
問題になりそうなものは
- 単純にMessageが多く、そもそも200個を超えてMessageを保持している謎のGtk::TimeLineがいる（ちなみにプロフィールと抽出タブを合わせて50個くらいタブを開いているので、プロフィール1つにつきTLとDMの2つGtk::TimeLineが生成されることを考えると、TLの個数自体は妥当だと思います）。
- mikutter内に存在する、意味のある（と想像される）オブジェクト数に対して、異常に巨大なハッシュが存在する
- スタックトレースの断片のようなものが見える（ただしこれは時間経過で増えないっぽい）
あたりだと思われます。ただそれにしても、memsize_of_allの結果と比べて実際の消費メモリが多すぎるのが少し気になります。
とりあえずはみんなから情報が集まるといいな。
ファイル
関連するチケット
Osamu Koga さんが約8年前に更新
明らかにGdk::Pixbufが漏れており、バカにならない容量を食っているようです。
>>> GC.start;ObjectSpace.each_object(Gdk::MiraclePainter).select{|m| m.instance_eval{@pixbuf}}.count
1194
>>> GC.start;ObjectSpace.each_object(Gdk::Pixbuf).count
3852
>>> GC.start;
mp_buf = Set[*ObjectSpace.each_object(Gdk::MiraclePainter).map{|m| m.instance_eval{@pixbuf}}.compact]
ObjectSpace.each_object(Gdk::Pixbuf).reject{|p| mp_buf.include?(p)}.reduce(0){|a,b| a + b.width*b.height*b.bits_per_sample/8*b.n_channels}
1245595332
これと関連して、同じようなオブジェクトが大量にゾンビ化するひとつの原因として、長生きするクロージャを作った時に不要なローカル変数を巻き込んでしまっている可能性があるのではないかと思いました。File.open('/tmp/procs.txt', 'w'){|f| f.puts(ObjectSpace.each_object(Proc).map(&:source_location).reject(&:nil?).map{|a| a.join(' ')})} の結果をStringと同様に集計すると、結構たくさん出てきます（一番上はssc）。
41534 /home/osak/app/mikutter/core/mui/gtk_extension.rb 28
10520 /home/osak/app/mikutter/core/mui/cairo_inner_tl.rb 198
6874 /home/osak/app/mikutter/core/mui/cairo_sub_parts_voter.rb 52
6874 /home/osak/app/mikutter/core/mui/cairo_sub_parts_voter.rb 32
6874 /home/osak/app/mikutter/core/mui/cairo_sub_parts_voter.rb 17
1781 /home/osak/.mikutter/plugin/sub_parts_client/sub_parts_client.rb 15
1781 /home/osak/.mikutter/plugin/geocode/geocode.rb 14
1776 /home/osak/app/mikutter/core/mui/cairo_coordinate_module.rb 85
1773 /home/osak/app/mikutter/core/mui/cairo_coordinate_module.rb 91
1439 /home/osak/.gem/gems/gobject-introspection-3.0.9/lib/gobject-introspection/loader.rb 553
1439 /home/osak/.gem/gems/gobject-introspection-3.0.9/lib/gobject-introspection/loader.rb 547
633 /home/osak/app/mikutter/core/lib/uithreadonly.rb 20
530 /home/osak/app/mikutter/core/mui/cairo_sub_parts_message_base.rb 180
477 /home/osak/.mikutter/plugin/mikutter-subparts-image/mikutter-subparts-image.rb 72
448 /home/osak/.mikutter/plugin/mikutter-subparts-image/mikutter-subparts-image.rb 151
448 /home/osak/.mikutter/plugin/mikutter-subparts-image/mikutter-subparts-image.rb 134
448 /home/osak/.mikutter/plugin/mikutter-subparts-image/mikutter-subparts-image.rb 116
292 /home/osak/app/mikutter/core/plugin/gtk/gtk.rb 490
292 /home/osak/app/mikutter/core/plugin/gtk/gtk.rb 149
292 /home/osak/app/mikutter/core/plugin/gtk/gtk.rb 142
292 /home/osak/app/mikutter/core/plugin/gtk/gtk.rb 140
292 /home/osak/app/mikutter/core/plugin/gtk/gtk.rb 136
237 /home/osak/app/mikutter/core/mui/gtk_tree_view_pretty_scroll.rb 31
237 /home/osak/app/mikutter/core/mui/gtk_tree_view_pretty_scroll.rb 16
234 /home/osak/app/mikutter/core/plugin/gui/gui.rb 58
234 /home/osak/app/mikutter/core/plugin/gui/gui.rb 52
232 /home/osak/app/mikutter/core/mui/gtk_tree_view_pretty_scroll.rb 20
222 /home/osak/.gem/gems/gobject-introspection-3.0.9/lib/gobject-introspection/loader.rb 255
166 /home/osak/.gem/gems/gobject-introspection-3.0.9/lib/gobject-introspection/loader.rb 109
166 /home/osak/.gem/gems/gobject-introspection-3.0.9/lib/gobject-introspection/loader.rb 103
mikutter-subparts-image.rbも上の方にいるので、画像のpixbufをsscに巻き込んでしまっているのかなという気がします。
toshi_a 初音 さんが約8年前に更新
TimelineがPixbuf、恐らくMiraclePainterを解放してない問題ですね。MiraclePainterにはそういう問題が存在している気がしていたので、これで証拠としては十分出たと思います。OSC終わったらこちらでも検証してみますね
Osamu Koga さんが約8年前に更新
#927 を適用＆mikutter-subparts-imageを外した状態でも、速度は遅いもののやはりじわじわとメモリ使用量が上がっていきます（約3日でVIRT10.2G / RES8.0G程度）。ただ、最初の報告時の倍の時間起動しっぱなしにしているにも関わらず、重複している文字列の個数は以前とそんなに変わっていません。
$ cat /tmp/strings.txt | sort | uniq -c | sort -k1 -r | head -n30 39550 fit 38585 ja 22407 C0DEED 21929 000000 18472 333333 16522 Tokyo 16148 none 13183 crop 13129 DDEEF6 13051 photo 12582 https 12580 twitter.com 11485 https://abs.twimg.com/images/themes/theme1/bg.png 11485 http://abs.twimg.com/images/themes/theme1/bg.png 10851 9043 1DA1F2 8145 FFFFFF 8140 low 8131 /home/osak/app/mikutter/core/lib/uithreadonly.rb:23:in `block (2 levels) in singleton class' 4716 219566976 4285 /home/osak/app/mikutter/core/mui/gtk_extension.rb:34:in `block in safety_signal_connect' 4134 njslyr 4030 mikutter.rb:92:in `<main>' 4030 mikutter.rb:63:in `boot!' 4030 /home/osak/app/mikutter/core/plugin/gtk/mainloop.rb:10:in `mainloop' 4030 /home/osak/app/mikutter/core/plugin/gtk/mainloop.rb:10:in `main' 3971 und 3755 http 3729 pbs.twimg.com 3563 recent
最初の投稿とほぼ同じような内容ですが、 #927 を適用しているにも関わらず、ニンジャスレイヤー関連の文字列（njslyr、219566976（@shonen_siriusのUser IDで、#njslyrタグを使ってニンジャスレイヤーのコミカライズを投稿している））が異常に多いのが気になります。ニンジャスレイヤー情報はSaved Searchとリストを使って追っているのですが、このへんの処理がおかしくて解放できていない何かがあるんじゃないかと思います。
toshi_a 初音 さんが約8年前に更新
listはUIをextractに任せているので、独自にUIを持っているsaved_searchが怪しい気がしますね。
こっちでも同じ方法で計測して、そんな感じの結果が出るかどうか試してみます
toshi_a 初音 さんが約8年前に更新
- 関連している 最適化 #945: Ruby-GNOME2 3.0.9を利用すると、mikutterが消費するメモリが増える を追加
操作