Bug #2067: bodyが大きいエラーページをopen-uriで取得するとfdがリークしている

• Status: Closed
• Assignee: -
• Target version: -
• ruby -v: ruby 1.9.1p243 (2009-07-16 revision 24175) [i386-darwin8]

[takeru (takeru sasaki)]

=begin
StringIOではなくTempFileが生成されるぐらい大きなHTTPエラーページを取得すると
open(url) do |f|
...
end
でブロック指定しているのにfdがopenされたままになっています。
=end

[takeru (takeru sasaki)]

=begin
begin
open(url) do |f|
...
end
rescue OpenURI::HTTPError => e
e.io.close
end
とすれば良いのですね。
しかし、すこしびっくりしました。

=end

[matz (Yukihiro Matsumoto)]

=begin
まつもと ゆきひろです

In message "Re: [ruby-dev:39284] Re: [Bug #2067] bodyが大きいエラーページをopen-uriで取得するとfdがリークしている"
on Thu, 10 Sep 2009 14:18:51 +0900, Nobuyoshi Nakada [e-mail] writes:

|> いや、そんなことしなければいけないのはやっぱりおかしいと思い
|> ますよ。なんでかな。
|
|エラーページの内容も例外の情報の一部になっているので、Tempfileを
|使っている場合には当然そうなるでしょう。
|
|エラーページの内容は捨ててしまうか、エラーのときにはサイズに関わ
|らずStringIOにするか、Tempfileなので気にしないことにするか。

部分的にしか理解できていません。Tempfileなのでcloseすると情報
が失われるから保存しているのは理解できました。が、その場合、
気になるのは、今回「リーク」とされたのは、ただちにcloseされて
いないからプロセスが肥大しただけのことで、いずれGCで回収され
るのかどうか、ということです。

そうでないなら、それはそれで確認しないと。

                             Tempfileは面倒だなあ。
                             まつもと ゆきひろ /:|)

=end

[takeru (takeru sasaki)]

=begin
言いだしっぺの佐々木です。

begin
open(url) do |f|
...
end
rescue OpenURI::HTTPError => e
e.io.close
end
GC.start
の様に書けば確実にcloseされるのなら問題ないですが、そうでもないようです。

GCでは未使用のメモリを回収してくれるだけで未使用のfdを回収してくれることは
ないのですよね。
メモリに余裕がある状態だとfdをつかんだ例外オブジェクトも回収されず、
fdも開きっぱなしになるのではないかとおもいます。
（再現スクリプトでは1.9では開きっぱなしのfdの数が少ないです。GCが効いている？）

この問題に気がついたのは、「EMFILE too many open files」になったせいでした。
例外オブジェクトへの参照は確実に無いはずで(メソッドからreturnしている)
gcされるより前にtoo many open filesにぶつかったのでした。
大きいサイズのエラーページというのもレアなのでなかなか気づきにくい問題でした。

2009年9月10日22:56 Tanaka Akira [e-mail]:

In article [e-mail],
Yukihiro Matsumoto [e-mail] writes:

部分的にしか理解できていません。Tempfileなのでcloseすると情報
が失われるから保存しているのは理解できました。が、その場合、
気になるのは、今回「リーク」とされたのは、ただちにcloseされて
いないからプロセスが肥大しただけのことで、いずれGCで回収され
るのかどうか、ということです。

例外オブジェクトへの参照がなくなれば、その例外オブジェクトや
Tempfile は GC されます。GC にともない、fd は close され、テ
ンポラリファイルは削除されます。

                            Tempfileは面倒だなあ。

[ruby-core:25019] で書いた Tempfile.anonymous {} のような、
状況によっては面倒でない挙動をとれる API をつければいくらか
は軽減できるでしょう。ただし、今回の open-uri の場合は例外の
中に入れるので適用できませんが。

[田中 哲][たなか あきら][Tanaka Akira]

=end

[matz (Yukihiro Matsumoto)]

=begin
まつもと ゆきひろです

In message "Re: [ruby-dev:39302] Re: [Bug #2067] bodyが大きいエラーページをopen-uriで取得するとfdがリークしている"
on Fri, 11 Sep 2009 01:34:01 +0900, takeru sasaki [e-mail] writes:

|GC.start
|の様に書けば確実にcloseされるのなら問題ないですが、そうでもないようです。

RubyのGCは保守的なのですべて回収されることは保証できません。

|GCでは未使用のメモリを回収してくれるだけで未使用のfdを回収してくれることは
|ないのですよね。
|メモリに余裕がある状態だとfdをつかんだ例外オブジェクトも回収されず、
|fdも開きっぱなしになるのではないかとおもいます。
|（再現スクリプトでは1.9では開きっぱなしのfdの数が少ないです。GCが効いている？）

GCは参照されていないオブジェクトを回収します。そのオブジェク
トがfdを持てば、それは自動的にcloseします。

|この問題に気がついたのは、「EMFILE too many open files」になったせいでした。
|例外オブジェクトへの参照は確実に無いはずで(メソッドからreturnしている)
|gcされるより前にtoo many open filesにぶつかったのでした。

RubyはEMFILEが発生すると自動的にGCを起動します。それでもなお
EMFILEが出ると言うことは、また別の問題を示唆しますね。

=end

[takeru (takeru sasaki)]

=begin
佐々木です。
ありがとうございます。

下記スクリプトを実行すると1.8（ちょっと古いのですが）では251回目で
Errno::EMFILEとなってしまいました。
例外オブジェクトが持つioがcloseされないようです。

しかし、1.9では2000回まで行きました。

======================
require "pp"
require "open-uri"

p [RUBY_VERSION,RUBY_PATCHLEVEL,RUBY_RELEASE_DATE,RUBY_PLATFORM]
pid = Process.pid
puts "pid=#{pid}"

url = "http://ssktkr.com/asdf"

puts "before -----------------------------"
puts lsof -p #{pid}
2000.times do |n|
puts "n=#{n}"
begin
open(url) do |f|
p f
end
rescue OpenURI::HTTPError => e
p e
pp e.backtrace
#e.io.close
end
end
GC.start
puts "after -----------------------------"
puts lsof -p #{pid}

ruby open_uri_bug.rb
["1.8.6", 114, "2008-03-03", "i686-darwin8.11.1"]
pid=29011
before -----------------------------
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
ruby 29011 takeru cwd DIR 14,2 4998 1356361 /Users/takeru/tmp
ruby 29011 takeru txt REG 14,2 13412 550135
/opt/local/bin/ruby
ruby 29011 takeru txt REG 14,2 23860 559917
/opt/local/lib/ruby/1.8/i686-darwin8.11.1/stringio.bundle
ruby 29011 takeru txt REG 14,2 783224 552430
/opt/local/lib/libruby.1.8.6.dylib
ruby 29011 takeru txt REG 14,2 1688500 1538264 /usr/lib/dyld
ruby 29011 takeru txt REG 14,2 8008576 7501385
/usr/lib/libSystem.B.dylib
ruby 29011 takeru txt REG 14,2 1580212 7501394
/usr/lib/libobjc.A.dylib
ruby 29011 takeru txt REG 14,2 3559472 7501739
/usr/lib/libstdc++.6.0.4.dylib
ruby 29011 takeru txt REG 14,2 251320 7501746
/usr/lib/libgcc_s.1.dylib
ruby 29011 takeru txt REG 14,2 212160 7501474
/usr/lib/libauto.dylib
ruby 29011 takeru 0u CHR 4,20 0t49144 61411076 /dev/ttyq4
ruby 29011 takeru 1u CHR 4,20 0t49144 61411076 /dev/ttyq4
ruby 29011 takeru 2u CHR 4,20 0t49144 61411076 /dev/ttyq4
ruby 29011 takeru 3 PIPE 0x400c248 16384
ruby 29011 takeru 11r PSXSHM 4096
apple.shm.notification_center
n=0
#<OpenURI::HTTPError: 404 Not Found>
["/opt/local/lib/ruby/1.8/open-uri.rb:278:in open_http'", "/opt/local/lib/ruby/1.8/open-uri.rb:617:in buffer_open'",
"/opt/local/lib/ruby/1.8/open-uri.rb:164:in open_loop'", "/opt/local/lib/ruby/1.8/open-uri.rb:162:in catch'",
"/opt/local/lib/ruby/1.8/open-uri.rb:162:in open_loop'", "/opt/local/lib/ruby/1.8/open-uri.rb:132:in open_uri'",
"/opt/local/lib/ruby/1.8/open-uri.rb:519:in open'", "/opt/local/lib/ruby/1.8/open-uri.rb:30:in open'",
"open_uri_bug.rb:15",
"open_uri_bug.rb:12:in times'", "open_uri_bug.rb:12"] n=1 #<OpenURI::HTTPError: 404 Not Found> ["/opt/local/lib/ruby/1.8/open-uri.rb:278:in open_http'",
"/opt/local/lib/ruby/1.8/open-uri.rb:617:in buffer_open'", "/opt/local/lib/ruby/1.8/open-uri.rb:164:in open_loop'",
"/opt/local/lib/ruby/1.8/open-uri.rb:162:in catch'", "/opt/local/lib/ruby/1.8/open-uri.rb:162:in open_loop'",
"/opt/local/lib/ruby/1.8/open-uri.rb:132:in open_uri'", "/opt/local/lib/ruby/1.8/open-uri.rb:519:in open'",
"/opt/local/lib/ruby/1.8/open-uri.rb:30:in open'", "open_uri_bug.rb:15", "open_uri_bug.rb:12:in times'",
"open_uri_bug.rb:12"]

(snip)

n=249
#<OpenURI::HTTPError: 404 Not Found>
["/opt/local/lib/ruby/1.8/open-uri.rb:278:in open_http'", "/opt/local/lib/ruby/1.8/open-uri.rb:617:in buffer_open'",
"/opt/local/lib/ruby/1.8/open-uri.rb:164:in open_loop'", "/opt/local/lib/ruby/1.8/open-uri.rb:162:in catch'",
"/opt/local/lib/ruby/1.8/open-uri.rb:162:in open_loop'", "/opt/local/lib/ruby/1.8/open-uri.rb:132:in open_uri'",
"/opt/local/lib/ruby/1.8/open-uri.rb:519:in open'", "/opt/local/lib/ruby/1.8/open-uri.rb:30:in open'",
"open_uri_bug.rb:15",
"open_uri_bug.rb:12:in times'", "open_uri_bug.rb:12"] n=250 #<OpenURI::HTTPError: 404 Not Found> ["/opt/local/lib/ruby/1.8/open-uri.rb:278:in open_http'",
"/opt/local/lib/ruby/1.8/open-uri.rb:617:in buffer_open'", "/opt/local/lib/ruby/1.8/open-uri.rb:164:in open_loop'",
"/opt/local/lib/ruby/1.8/open-uri.rb:162:in catch'", "/opt/local/lib/ruby/1.8/open-uri.rb:162:in open_loop'",
"/opt/local/lib/ruby/1.8/open-uri.rb:132:in open_uri'", "/opt/local/lib/ruby/1.8/open-uri.rb:519:in open'",
"/opt/local/lib/ruby/1.8/open-uri.rb:30:in open'", "open_uri_bug.rb:15", "open_uri_bug.rb:12:in times'",
"open_uri_bug.rb:12"]
n=251
/opt/local/lib/ruby/1.8/tempfile.rb:55:in initialize': Too many open files - /tmp/open-uri.29011.251 (Errno::EMFILE) from /opt/local/lib/ruby/1.8/tempfile.rb:55:in open'
from /opt/local/lib/ruby/1.8/tempfile.rb:55:in initialize' from /opt/local/lib/ruby/1.8/open-uri.rb:303:in new'
from /opt/local/lib/ruby/1.8/open-uri.rb:303:in <<' from /opt/local/lib/ruby/1.8/open-uri.rb:259:in open_http'
from /opt/local/lib/ruby/1.8/net/protocol.rb:381:in call_block' from /opt/local/lib/ruby/1.8/net/protocol.rb:372:in <<'
from /opt/local/lib/ruby/1.8/net/protocol.rb:84:in read' ... 15 levels... from /opt/local/lib/ruby/1.8/open-uri.rb:30:in open'
from open_uri_bug.rb:15
from open_uri_bug.rb:12:in `times'
from open_uri_bug.rb:12
tkrmb:tmp%

2009年9月11日7:46 Yukihiro Matsumoto [e-mail]:

まつもと ゆきひろです

In message "Re: [ruby-dev:39302] Re: [Bug #2067] bodyが大きいエラーページをopen-uriで取得するとfdがリークしている"
on Fri, 11 Sep 2009 01:34:01 +0900, takeru sasaki [e-mail] writes:

|GC.start
|の様に書けば確実にcloseされるのなら問題ないですが、そうでもないようです。

RubyのGCは保守的なのですべて回収されることは保証できません。

|GCでは未使用のメモリを回収してくれるだけで未使用のfdを回収してくれることは
|ないのですよね。
|メモリに余裕がある状態だとfdをつかんだ例外オブジェクトも回収されず、
|fdも開きっぱなしになるのではないかとおもいます。
|（再現スクリプトでは1.9では開きっぱなしのfdの数が少ないです。GCが効いている？）

GCは参照されていないオブジェクトを回収します。そのオブジェク
トがfdを持てば、それは自動的にcloseします。

|この問題に気がついたのは、「EMFILE too many open files」になったせいでした。
|例外オブジェクトへの参照は確実に無いはずで(メソッドからreturnしている)
|gcされるより前にtoo many open filesにぶつかったのでした。

RubyはEMFILEが発生すると自動的にGCを起動します。それでもなお
EMFILEが出ると言うことは、また別の問題を示唆しますね。

=end

[matz (Yukihiro Matsumoto)]

=begin
まつもと ゆきひろです

In message "Re: [ruby-dev:39309] Re: [Bug #2067] bodyが大きいエラーページをopen-uriで取得するとfdがリークしている"
on Fri, 11 Sep 2009 16:02:58 +0900, Tanaka Akira [e-mail] writes:

|縮めるとこんな感じでしょうか。
|
|tmperr() {} を tmperr() にすると回収されるようになるのが非常
|に怪しいです。

うーん、マシンスタックに例外オブジェクトへの参照が残ってしまっ
てるのかもしれませんね。この辺が保守的GCの弱いところです。
MBARIパッチで挙動が変わったりするんでしょうか。

=end

[shyouhei (Shyouhei Urabe)]

=begin
Tanaka Akira さんは書きました:

In article [e-mail],
Yukihiro Matsumoto [e-mail] writes:

うーん、マシンスタックに例外オブジェクトへの参照が残ってしまっ
てるのかもしれませんね。この辺が保守的GCの弱いところです。

保守的GCは便利ないいわけですが、たぶん違います。

callback で生成した Proc オブジェクトの中から例外オブジェク
トが参照されている感じですが、どういう理屈でそうなるのかはよ
くわかりません。

tmpfile使わない版だとこんな感じ?

zsh % ~/target/svn/ruby_1_8/bin/ruby
class Err < StandardError
def initialize obj
@io = obj
end
end

def cb
proc {}
end

def tmperr
tmpf = [open("/dev/null")]
ObjectSpace.define_finalizer tmpf, cb
raise Err.new(tmpf)
end

loop do
begin
tmperr(){}
rescue Err => e
end
end
^D
-:12:in initialize': Too many open files - /dev/null (Errno::EMFILE) from -:12:in open'
from -:12:in tmperr' from -:19 from -:17:in loop'
from -:17
zsh: exit 1 ~/target/svn/ruby_1_8/bin/ruby

=end

[akr (Akira Tanaka)]

• Status changed from Open to Closed

=begin

=end