Project

General

Profile

Bug #8644

valgrind error in a readline test

Added by Akira Tanaka over 3 years ago. Updated over 3 years ago.

Status:
Closed
Priority:
Normal
Assignee:
ruby -v:
ruby 2.1.0dev (2013-07-16 trunk 42006) [x86_64-linux]
[ruby-dev:<unknown>]

Description

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

% ./ruby -v
ruby 2.1.0dev (2013-07-16 trunk 42006) [x86_64-linux]
% valgrind ./ruby -I.ext/x86_64-linux ../../ruby/test/runner.rb ../../ruby/test/readline -n test_closed_outstream
==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/x86_64-linux ../../ruby/test/runner.rb ../../ruby/test/readline -n test_closed_outstream
==27651==
Run options: -n test_closed_outstream

# Running tests:

[1/1] TestReadline#test_closed_outstream==27651== Invalid read of size 4
==27651== at 0x597B610: fileno (fileno.c:37)
==27651== by 0x74A3EA6: readline_readline (readline.c:397)
==27651== by 0x390B39: call_cfunc_m1 (vm_insnhelper.c:1348)
==27651== by 0x396943: vm_call_cfunc_with_frame (vm_insnhelper.c:1492)
==27651== by 0x395144: vm_call_cfunc (vm_insnhelper.c:1582)
==27651== by 0x394915: vm_call_method (vm_insnhelper.c:1774)
==27651== by 0x396A84: vm_call_general (vm_insnhelper.c:1925)
==27651== by 0x3724DC: vm_exec_core (insns.def:1017)
==27651== by 0x383DDF: vm_exec (vm.c:1198)
==27651== by 0x389DBD: invoke_block_from_c (vm.c:646)
==27651== by 0x38E299: vm_yield (vm.c:677)
==27651== by 0x380012: rb_yield_0 (vm_eval.c:937)
==27651== Address 0x847a1a0 is 0 bytes inside a block of size 568 free'd
==27651== at 0x4C27D4E: free (vg_replace_malloc.c:427)
==27651== by 0x5977CCC: fclose@@GLIBC_2.2.5 (iofclose.c:88)
==27651== by 0x190F5C: nogvl_fclose (io.c:4048)
==27651== by 0x3A33FC: call_without_gvl (thread.c:1244)
==27651== by 0x3A3532: rb_thread_call_without_gvl (thread.c:1354)
==27651== by 0x190E7C: maygvl_fclose (io.c:4057)
==27651== by 0x190620: fptr_finalize (io.c:4099)
==27651== by 0x16C922: rb_io_fptr_cleanup (io.c:4130)
==27651== by 0x16CAE7: rb_io_close (io.c:4221)
==27651== by 0x17A2F1: rb_io_close_m (io.c:4250)
==27651== by 0x390B62: call_cfunc_0 (vm_insnhelper.c:1354)
==27651== by 0x396943: vm_call_cfunc_with_frame (vm_insnhelper.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 したときのログもつけておきます。
(長すぎるので消しました。test_closed_outstream-segv.txt をみてください。)

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

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


Related issues

Related to Ruby trunk - Bug #12950: irb: 'input-method.rb:151: [BUG] Segmentation fault' / 'malloc(): smallbin double linked list corrupted' Feedback

Associated revisions

Revision 42402
Added by Kouji Takao over 3 years ago

  • ext/readline/readline.c (Init_readline, readline_s_set_output) (clear_rl_outstream, readline_s_set_input, clear_rl_instream) (readline_readline): fix causing SEGV if closed IO object that is set Readline.input or Readline.output. Patched by akr [Bug #8644]

Revision 42402
Added by Kouji Takao over 3 years ago

  • ext/readline/readline.c (Init_readline, readline_s_set_output) (clear_rl_outstream, readline_s_set_input, clear_rl_instream) (readline_readline): fix causing SEGV if closed IO object that is set Readline.input or Readline.output. Patched by akr [Bug #8644]

Revision 42402
Added by Kouji Takao over 3 years ago

  • ext/readline/readline.c (Init_readline, readline_s_set_output) (clear_rl_outstream, readline_s_set_input, clear_rl_instream) (readline_readline): 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 over 3 years ago

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

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

Revision 42525
Added by Yui NARUSE over 3 years ago

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

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

Revision 42525
Added by Yui NARUSE over 3 years ago

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

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

History

#1 [ruby-dev:47509] Updated by Akira Tanaka over 3 years ago

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

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

#2 [ruby-dev:47525] Updated by Akira Tanaka over 3 years ago

  • Description updated (diff)

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

#3 [ruby-dev:47527] Updated by Akira Tanaka over 3 years 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: readline_readline (readline.c:394)
==10001== by 0x258AFE: call_cfunc_m1 (vm_insnhelper.c:1348)
==10001== by 0x2596EE: vm_call_cfunc_with_frame (vm_insnhelper.c:1492)
==10001== by 0x259828: vm_call_cfunc (vm_insnhelper.c:1582)
==10001== by 0x25A368: vm_call_method (vm_insnhelper.c:1774)
==10001== by 0x25AB02: vm_call_general (vm_insnhelper.c:1925)
==10001== by 0x25E4D0: vm_exec_core (insns.def:1017)
==10001== by 0x26D8C8: vm_exec (vm.c:1198)
==10001== by 0x26E53C: rb_iseq_eval_main (vm.c:1448)
==10001== by 0x12D3CC: ruby_exec_internal (eval.c:252)
==10001== by 0x12D4DF: ruby_exec_node (eval.c:317)
==10001== Address 0x6e5f970 is 0 bytes inside a block of size 568 free'd
==10001== at 0x4C240FD: free (vg_replace_malloc.c:366)
==10001== by 0x596CD5C: fclose@@GLIBC_2.2.5 (iofclose.c:88)
==10001== by 0x156E76: nogvl_fclose (io.c:4048)
==10001== by 0x27AB3D: call_without_gvl (thread.c:1244)
==10001== by 0x27AC6F: rb_thread_call_without_gvl (thread.c:1354)
==10001== by 0x156EBC: maygvl_fclose (io.c:4057)
==10001== by 0x157014: fptr_finalize (io.c:4099)
==10001== by 0x15712B: rb_io_fptr_cleanup (io.c:4130)
==10001== by 0x15740C: rb_io_close (io.c:4221)
==10001== by 0x157464: rb_io_close_m (io.c:4250)
==10001== by 0x258B2E: call_cfunc_0 (vm_insnhelper.c:1354)
==10001== by 0x2596EE: vm_call_cfunc_with_frame (vm_insnhelper.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: readline_readline (readline.c:397)
==9994== by 0x258AFE: call_cfunc_m1 (vm_insnhelper.c:1348)
==9994== by 0x2596EE: vm_call_cfunc_with_frame (vm_insnhelper.c:1492)
==9994== by 0x259828: vm_call_cfunc (vm_insnhelper.c:1582)
==9994== by 0x25A368: vm_call_method (vm_insnhelper.c:1774)
==9994== by 0x25AB02: vm_call_general (vm_insnhelper.c:1925)
==9994== by 0x25E4D0: vm_exec_core (insns.def:1017)
==9994== by 0x26D8C8: vm_exec (vm.c:1198)
==9994== by 0x26E53C: rb_iseq_eval_main (vm.c:1448)
==9994== by 0x12D3CC: ruby_exec_internal (eval.c:252)
==9994== by 0x12D4DF: ruby_exec_node (eval.c:317)
==9994== Address 0x6e5fbf0 is 0 bytes inside a block of size 568 free'd
==9994== at 0x4C240FD: free (vg_replace_malloc.c:366)
==9994== by 0x596CD5C: fclose@@GLIBC_2.2.5 (iofclose.c:88)
==9994== by 0x156E76: nogvl_fclose (io.c:4048)
==9994== by 0x27AB3D: call_without_gvl (thread.c:1244)
==9994== by 0x27AC6F: rb_thread_call_without_gvl (thread.c:1354)
==9994== by 0x156EBC: maygvl_fclose (io.c:4057)
==9994== by 0x157014: fptr_finalize (io.c:4099)
==9994== by 0x15712B: rb_io_fptr_cleanup (io.c:4130)
==9994== by 0x15740C: rb_io_close (io.c:4221)
==9994== by 0x157464: rb_io_close_m (io.c:4250)
==9994== by 0x258B2E: call_cfunc_0 (vm_insnhelper.c:1354)
==9994== by 0x2596EE: vm_call_cfunc_with_frame (vm_insnhelper.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]

問題は、readline_s_set_input や readline_s_set_output で、
IO オブジェクトから rb_io_stdio_file で FILE * を入手し、
rl_instream や rl_outstream へ代入していることにあります。

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

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

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

#4 [ruby-dev:47528] Updated by Akira Tanaka over 3 years 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 [ruby-dev:47529] Updated by Kouji Takao over 3 years ago

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

#6 Updated by Akira Tanaka over 3 years ago

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

...
TestRange#test_bsearch_for_other_numerics = s = .
TestRange#test_bsearch_typechecks_return_values = s = .
+TestRange#test_bsearch_with_mathn = /home/chkbuild/build//ruby/test/readline/test_readline.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 していて、
test_readline.rb:299 というのは test_closed_outstream 内の
Readline.readline を呼び出しているところで、
なかなか怪しいんじゃないかと思うんですが、どうですかね。

#7 Updated by Kouji Takao over 3 years ago

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

#8 Updated by Kouji Takao over 3 years ago

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

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 (Init_readline, readline_s_set_output) (clear_rl_outstream, readline_s_set_input, clear_rl_instream) (readline_readline): fix causing SEGV if closed IO object that is set Readline.input or Readline.output. Patched by akr [Bug #8644]

#9 Updated by _ wanabe 10 days ago

  • Related to Bug #12950: irb: 'input-method.rb:151: [BUG] Segmentation fault' / 'malloc(): smallbin double linked list corrupted' added

Also available in: Atom PDF