Bug #8644

valgrind error in a readline test

Added by Akira Tanaka 9 months ago. Updated 9 months ago.

[ruby-dev:<unknown>]
Status:Closed
Priority:Normal
Assignee:Kouji Takao
Category:ext
Target version:next minor
ruby -v:ruby 2.1.0dev (2013-07-16 trunk 42006) [x86_64-linux] Backport:1.9.3: UNKNOWN, 2.0.0: UNKNOWN

Description

test-all が readline のところで SEGV することがあったので、
とりあえず valgrind をかけてみたところ、ひとつ問題を指摘されました。

% ./ruby -v
ruby 2.1.0dev (2013-07-16 trunk 42006) [x8664-linux]
% valgrind ./ruby -I.ext/x86
64-linux ../../ruby/test/runner.rb ../../ruby/test/readline -n testclosedoutstream
==27651== Memcheck, a memory error detector
==27651== Copyright (C) 2002-2011, and GNU GPL'd, by Julian Seward et al.
==27651== Using Valgrind-3.7.0 and LibVEX; rerun with -h for copyright info
==27651== Command: ./ruby -I.ext/x8664-linux ../../ruby/test/runner.rb ../../ruby/test/readline -n testclosedoutstream
==27651==
Run options: -n test
closed_outstream

# Running tests:

[1/1] TestReadline#testclosedoutstream==27651== Invalid read of size 4
==27651== at 0x597B610: fileno (fileno.c:37)
==27651== by 0x74A3EA6: readlinereadline (readline.c:397)
==27651== by 0x390B39: call
cfuncm1 (vminsnhelper.c:1348)
==27651== by 0x396943: vmcallcfuncwithframe (vminsnhelper.c:1492)
==27651== by 0x395144: vm
callcfunc (vminsnhelper.c:1582)
==27651== by 0x394915: vmcallmethod (vminsnhelper.c:1774)
==27651== by 0x396A84: vm
callgeneral (vminsnhelper.c:1925)
==27651== by 0x3724DC: vmexeccore (insns.def:1017)
==27651== by 0x383DDF: vmexec (vm.c:1198)
==27651== by 0x389DBD: invoke
blockfromc (vm.c:646)
==27651== by 0x38E299: vmyield (vm.c:677)
==27651== by 0x380012: rb
yield0 (vmeval.c:937)
==27651== Address 0x847a1a0 is 0 bytes inside a block of size 568 free'd
==27651== at 0x4C27D4E: free (vgreplacemalloc.c:427)
==27651== by 0x5977CCC: fclose@@GLIBC2.2.5 (iofclose.c:88)
==27651== by 0x190F5C: nogvl
fclose (io.c:4048)
==27651== by 0x3A33FC: callwithoutgvl (thread.c:1244)
==27651== by 0x3A3532: rbthreadcallwithoutgvl (thread.c:1354)
==27651== by 0x190E7C: maygvlfclose (io.c:4057)
==27651== by 0x190620: fptr
finalize (io.c:4099)
==27651== by 0x16C922: rbiofptrcleanup (io.c:4130)
==27651== by 0x16CAE7: rb
ioclose (io.c:4221)
==27651== by 0x17A2F1: rb
ioclosem (io.c:4250)
==27651== by 0x390B62: callcfunc0 (vminsnhelper.c:1354)
==27651== by 0x396943: vm
callcfuncwithframe (vminsnhelper.c:1492)
==27651==
Finished tests in 0.521803s, 1.9164 tests/s, 5.7493 assertions/s.
1 tests, 3 assertions, 0 failures, 0 errors, 0 skips

ruby -v: ruby 2.1.0dev (2013-07-16 trunk 42006) [x86_64-linux]
==27651==
==27651== HEAP SUMMARY:
==27651== in use at exit: 1,905,554 bytes in 30,452 blocks
==27651== total heap usage: 94,021 allocs, 63,569 frees, 19,535,963 bytes allocated
==27651==
==27651== LEAK SUMMARY:
==27651== definitely lost: 447,671 bytes in 3,643 blocks
==27651== indirectly lost: 979,312 bytes in 17,524 blocks
==27651== possibly lost: 0 bytes in 0 blocks
==27651== still reachable: 478,571 bytes in 9,285 blocks
==27651== suppressed: 0 bytes in 0 blocks
==27651== Rerun with --leak-check=full to see details of leaked memory
==27651==
==27651== For counts of detected and suppressed errors, rerun with: -v
==27651== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 4 from 4)

ちょっとソースを見たところ、fclose した後に fileno しているようですが、
これはよろしくないんじゃないでしょうか。

valgrind で指摘されたのが原因かどうかはわかりませんが、
SEGV したときのログもつけておきます。
(長すぎるので消しました。testclosedoutstream-segv.txt をみてください。)

test_closed_outstream-segv.txt Magnifier (166 KB) Akira Tanaka, 07/16/2013 09:47 PM

readline-fix-invalid-read.patch Magnifier (5.14 KB) Akira Tanaka, 07/18/2013 11:02 PM

Associated revisions

Revision 42402
Added by Kouji Takao 9 months ago

  • ext/readline/readline.c (Initreadline, readlinessetoutput) (clearrloutstream, readlinessetinput, clearrlinstream) (readlinereadline): fix causing SEGV if closed IO object that is set Readline.input or Readline.output. Patched by akr [Bug #8644]

Revision 42525
Added by Yui NARUSE 9 months ago

  • ext/readline/readline.c (readlinessetinput): on OS X with editline,
    Readline.readline doesn't work because readline
    get doesn't use
    rlgetc. The difference is introduced by r42402
    [Bug #8644]. Before it rb
    iostdiofile set ifp->stdio_file.
    Therefore add manually setting the value.

  • ext/readline/readline.c (readlinesset_onput): ditto.

History

#1 Updated by Akira Tanaka 9 months ago

readline のテストについて報告したのですが、
内容が長すぎたのか、途切れてしまったので、
SEGV したときのログを添付します。

あと、長すぎたためか、メールも ruby-dev には流れなかったようです。

#2 Updated by Akira Tanaka 9 months ago

  • Description updated (diff)

SEGV のログは長すぎたので issue の本文からは消しました。

#3 Updated by Akira Tanaka 9 months ago

調べてみると、テストにある、Readline.output に設定した
IO オブジェクトを close した場合だけでなく、
Readline.input に設定した IO オブジェクトを close した場合にも
Invalid read が起こるようです。
以下のようにして確認できます。

% valgrind ./ruby -rreadline -e '
r, w = IO.pipe
Readline.input = r
Readline.output = w
r.close
Readline.readline'
==10001== Memcheck, a memory error detector
==10001== Copyright (C) 2002-2010, and GNU GPL'd, by Julian Seward et al.
==10001== Using Valgrind-3.6.0.SVN-Debian and LibVEX; rerun with -h for copyright info
==10001== Command: ./ruby -rreadline -e
==10001== r,\ w\ =\ IO.pipe
==10001== Readline.input\ =\ r
==10001== Readline.output\ =\ w
==10001== r.close
==10001== Readline.readline
==10001==
==10001== Invalid read of size 4
==10001== at 0x59706A0: fileno (fileno.c:37)
==10001== by 0x6EDB699: readlinereadline (readline.c:394)
==10001== by 0x258AFE: call
cfuncm1 (vminsnhelper.c:1348)
==10001== by 0x2596EE: vmcallcfuncwithframe (vminsnhelper.c:1492)
==10001== by 0x259828: vm
callcfunc (vminsnhelper.c:1582)
==10001== by 0x25A368: vmcallmethod (vminsnhelper.c:1774)
==10001== by 0x25AB02: vm
callgeneral (vminsnhelper.c:1925)
==10001== by 0x25E4D0: vmexeccore (insns.def:1017)
==10001== by 0x26D8C8: vmexec (vm.c:1198)
==10001== by 0x26E53C: rb
iseqevalmain (vm.c:1448)
==10001== by 0x12D3CC: rubyexecinternal (eval.c:252)
==10001== by 0x12D4DF: rubyexecnode (eval.c:317)
==10001== Address 0x6e5f970 is 0 bytes inside a block of size 568 free'd
==10001== at 0x4C240FD: free (vgreplacemalloc.c:366)
==10001== by 0x596CD5C: fclose@@GLIBC2.2.5 (iofclose.c:88)
==10001== by 0x156E76: nogvl
fclose (io.c:4048)
==10001== by 0x27AB3D: callwithoutgvl (thread.c:1244)
==10001== by 0x27AC6F: rbthreadcallwithoutgvl (thread.c:1354)
==10001== by 0x156EBC: maygvlfclose (io.c:4057)
==10001== by 0x157014: fptr
finalize (io.c:4099)
==10001== by 0x15712B: rbiofptrcleanup (io.c:4130)
==10001== by 0x15740C: rb
ioclose (io.c:4221)
==10001== by 0x157464: rb
ioclosem (io.c:4250)
==10001== by 0x258B2E: callcfunc0 (vminsnhelper.c:1354)
==10001== by 0x2596EE: vm
callcfuncwithframe (vminsnhelper.c:1492)
==10001==
-e:6:in readline': closed stdin (IOError)
from -e:6:in
'
==10001==
==10001== HEAP SUMMARY:
==10001== in use at exit: 1,503,865 bytes in 23,682 blocks
==10001== total heap usage: 41,787 allocs, 18,105 frees, 8,853,637 bytes allocated
==10001==
==10001== LEAK SUMMARY:
==10001== definitely lost: 453,958 bytes in 4,422 blocks
==10001== indirectly lost: 696,055 bytes in 12,524 blocks
==10001== possibly lost: 121 bytes in 1 blocks
==10001== still reachable: 353,731 bytes in 6,735 blocks
==10001== suppressed: 0 bytes in 0 blocks
==10001== Rerun with --leak-check=full to see details of leaked memory
==10001==
==10001== For counts of detected and suppressed errors, rerun with: -v
==10001== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 4 from 4)
zsh: exit 1 valgrind ./ruby -rreadline -e

ついでに、Readline.output のほうも test でなく単独で確認するには以下のようにできます。

% valgrind ./ruby -rreadline -e '
r, w = IO.pipe
Readline.input = r
Readline.output = w
w.close
Readline.readline'
==9994== Memcheck, a memory error detector
==9994== Copyright (C) 2002-2010, and GNU GPL'd, by Julian Seward et al.
==9994== Using Valgrind-3.6.0.SVN-Debian and LibVEX; rerun with -h for copyright info
==9994== Command: ./ruby -rreadline -e
==9994== r,\ w\ =\ IO.pipe
==9994== Readline.input\ =\ r
==9994== Readline.output\ =\ w
==9994== w.close
==9994== Readline.readline
==9994==
==9994== Invalid read of size 4
==9994== at 0x59706A0: fileno (fileno.c:37)
==9994== by 0x6EDB6EF: readlinereadline (readline.c:397)
==9994== by 0x258AFE: call
cfuncm1 (vminsnhelper.c:1348)
==9994== by 0x2596EE: vmcallcfuncwithframe (vminsnhelper.c:1492)
==9994== by 0x259828: vm
callcfunc (vminsnhelper.c:1582)
==9994== by 0x25A368: vmcallmethod (vminsnhelper.c:1774)
==9994== by 0x25AB02: vm
callgeneral (vminsnhelper.c:1925)
==9994== by 0x25E4D0: vmexeccore (insns.def:1017)
==9994== by 0x26D8C8: vmexec (vm.c:1198)
==9994== by 0x26E53C: rb
iseqevalmain (vm.c:1448)
==9994== by 0x12D3CC: rubyexecinternal (eval.c:252)
==9994== by 0x12D4DF: rubyexecnode (eval.c:317)
==9994== Address 0x6e5fbf0 is 0 bytes inside a block of size 568 free'd
==9994== at 0x4C240FD: free (vgreplacemalloc.c:366)
==9994== by 0x596CD5C: fclose@@GLIBC2.2.5 (iofclose.c:88)
==9994== by 0x156E76: nogvl
fclose (io.c:4048)
==9994== by 0x27AB3D: callwithoutgvl (thread.c:1244)
==9994== by 0x27AC6F: rbthreadcallwithoutgvl (thread.c:1354)
==9994== by 0x156EBC: maygvlfclose (io.c:4057)
==9994== by 0x157014: fptr
finalize (io.c:4099)
==9994== by 0x15712B: rbiofptrcleanup (io.c:4130)
==9994== by 0x15740C: rb
ioclose (io.c:4221)
==9994== by 0x157464: rb
ioclosem (io.c:4250)
==9994== by 0x258B2E: callcfunc0 (vminsnhelper.c:1354)
==9994== by 0x2596EE: vm
callcfuncwithframe (vminsnhelper.c:1492)
==9994==
-e:6:in readline': closed stdout (IOError)
from -e:6:in
'
==9994==
==9994== HEAP SUMMARY:
==9994== in use at exit: 1,503,865 bytes in 23,682 blocks
==9994== total heap usage: 41,787 allocs, 18,105 frees, 8,853,637 bytes allocated
==9994==
==9994== LEAK SUMMARY:
==9994== definitely lost: 453,958 bytes in 4,422 blocks
==9994== indirectly lost: 696,055 bytes in 12,524 blocks
==9994== possibly lost: 121 bytes in 1 blocks
==9994== still reachable: 353,731 bytes in 6,735 blocks
==9994== suppressed: 0 bytes in 0 blocks
==9994== Rerun with --leak-check=full to see details of leaked memory
==9994==
==9994== For counts of detected and suppressed errors, rerun with: -v
==9994== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 4 from 4)
zsh: exit 1 valgrind ./ruby -rreadline -e

% ./ruby -v
ruby 2.1.0dev (2013-07-18 trunk 42040) [x86_64-linux]

問題は、readlinessetinput や readlinessetoutput で、
IO オブジェクトから rbiostdiofile で FILE * を入手し、
rl
instream や rl_outstream へ代入していることにあります。

IO#close では rlinstream や rloutstream に残っていることは気にせず、
FILE * を fclose し、ファイル構造体は開放されるので、
その後で (readlinereadline で) fileno(rlinstream) や fileno(rl_outstream) をすると
Invalid read になります。
もし、ファイル構造体のあったメモリが OS に返却されていれば SEGV になってもおかしくないでしょう。

rbiostdiofile で入手した FILE * はいつ消えてもおかしくないので、
rl
instream や rl_outstream へ代入してとっておくのはよろしくないのではないでしょうか。
ファイル構造体をどうしてもとっておく必要があるなら、おそらく、fd を dup して fdopen で
ファイル構造体を新しく作って代入するような方向性がいいんじゃないでしょうか。

もちろん、そうやって dup/fdopen で資源 (新しい fd, ファイル構造体) を確保するなら
開放する手立ても必要でしょう。
readlinereadline で errno == EBADF で検査する代わりにもともとの IO オブジェクトが
クローズされているかどうかを調べてクローズされていたら開放するとか、
readline
ssetinput や readlinesset_output で nil を受け付けるとか、
いくつか考えないといけないとは思います。

#4 Updated by Akira Tanaka 9 months ago

とりあえず、close されたかどうかは元々の IO オブジェクトが
close されたかどうかで判断するようなパッチを書いてみたんですが、
どうですかね。

なお、やってみて気がついたのですが、
isatty して EBADF になることを確認するというコードがあって、
しかも Readline.readline のドキュメントにその挙動が

  • Raises IOError exception if below conditions are satisfied.
  • 1. stdin is not tty.
  • 2. stdin was closed. (errno is EBADF after called isatty(2).)

と明記されているのですが、
そもそも EBADF を検査するのは間違っている (常に他のスレッドや
signal handler が fd を open する可能性はあるので確実でない) というのと、
実際に isatty で tty でないときに IOError にしてみたら、
テストが失敗しまくる (テストではパイプを stdin に設定している)
というわけで、ここは isatty は気にしないように変えてみました。

#5 Updated by Kouji Takao 9 months ago

  • Category set to ext
  • Status changed from Open to Assigned
  • Assignee set to Kouji Takao
  • Target version set to next minor

#6 Updated by Akira Tanaka 9 months ago

http://rbci.lakewood.privs.net/ruby-trunk/log/20130801T131001Z.diff.html.gz をみると、

...
TestRange#testbsearchforothernumerics = s = .
TestRange#testbsearchtypechecksreturnvalues = s = .
+TestRange#testbsearchwithmathn = /home/chkbuild/build//ruby/test/readline/testreadline.rb:299: [BUG] Segmentation fault
ruby

+-- Control frame information -----------------------------------------------
+c:0028 p:---- s:0127 e:000126 CFUNC :readline
+c:0027 p:0013 s:0124 e:000123 BLOCK /home/chkbuild/build//ruby/test/readline/test_readline.rb:299
+c:0026 p:0036 s:0122 e:000121 METHOD /home/chkbuild/build//ruby/lib/minitest/unit.rb:362
...

みたいな感じで SEGV していて、
testreadline.rb:299 というのは testclosed_outstream 内の
Readline.readline を呼び出しているところで、
なかなか怪しいんじゃないかと思うんですが、どうですかね。

#7 Updated by Kouji Takao 9 months ago

パッチありがとうございます。取り込みます。

#8 Updated by Kouji Takao 9 months ago

  • Status changed from Assigned to Closed
  • % Done changed from 0 to 100

This issue was solved with changeset r42402.
Akira, thank you for reporting this issue.
Your contribution to Ruby is greatly appreciated.
May Ruby be with you.


  • ext/readline/readline.c (Initreadline, readlinessetoutput) (clearrloutstream, readlinessetinput, clearrlinstream) (readlinereadline): fix causing SEGV if closed IO object that is set Readline.input or Readline.output. Patched by akr [Bug #8644]

Also available in: Atom PDF