Bug #1954: line number 0?

• Status: Closed
• Assignee: ko1 (Koichi Sasada)
• Target version: 1.9.2
• ruby -v: ruby 1.9.2dev (2009-08-18 trunk 24578) [i686-linux]

[znz (Kazuhiro NISHIYAMA)]

=begin
$DEBUG = true の時に出てくる例外発生位置の行番号が 0 になってしまうことがあるようです。

% cat t0.rb
$DEBUG = true
Thread.start do
begin
Process.kill(:INT, $$)
ensure
raise
end
end.join
% ruby-trunk t0.rb
Exception Interrupt' at t0.rb:2 - Exception RuntimeError' at t0.rb:6 -
Exception RuntimeError' at t0.rb:0 - t0.rb:2:in join': Interrupt
from t0.rb:2:in `'

% ruby-trunk -v
ruby 1.9.2dev (2009-08-18 trunk 24578) [i686-linux]
%
=end

[yugui (Yuki Sonoda)]

• Status changed from Open to Assigned
• Assignee set to ko1 (Koichi Sasada)
• Target version set to 1.9.2

=begin

=end

[rogerdpack (Roger Pack)]

=begin
Is this still the case, at all?
-r
=end

[znz (Kazuhiro NISHIYAMA)]

=begin
まだ再現します。
他の環境でも再現するか確かめやすくするため、 r26244 でテストを追加しました。

他のバージョンと挙動を比べてみると

• REE: "in ensure" が出てこない
• 1.9.1: :0
• trunk: t1.rb:0
• 1.9.1とtrunk: t1.rb:2 が start ではなく join になっている
  というところがおかしいように見えます。

% cat t1.rb
$DEBUG = true
Thread.start do
begin
Process.kill(:INT, $$)
ensure
raise "in ensure"
end
end.join
% ruby-1.8.6 -v t1.rb
ruby 1.8.6 (2009-08-26 patchlevel 387) [x86_64-linux]
Exception Interrupt' at t1.rb:2 - Exception RuntimeError' at t1.rb:6 - in ensure
t1.rb:2:in `start': Interrupt
from t1.rb:2

% ruby-1.8.7 -v t1.rb
ruby 1.8.7 (2009-12-24 patchlevel 248) [x86_64-linux]
Exception Interrupt' at t1.rb:2 - Exception RuntimeError' at t1.rb:6 - in ensure
t1.rb:2:in `start': Interrupt
from t1.rb:2

% ruby18 -v t1.rb
ruby 1.8.8dev (2010-01-01 revision 26226) [x86_64-linux]
Exception Interrupt' at t1.rb:2 - Exception RuntimeError' at t1.rb:6 - in ensure
t1.rb:2:in `start': Interrupt
from t1.rb:2

% ruby -v t1.rb
ruby 1.8.7 (2009-06-12 patchlevel 174) [x86_64-linux], MBARI 0x6770, Ruby Enterprise Edition 2009.10
Exception Interrupt' at t1.rb:2 - t1.rb:2:in start': Interrupt
from t1.rb:2

% ruby-1.9.1 -v t1.rb
ruby 1.9.1p376 (2009-12-07 revision 26040) [x86_64-linux]
Exception Interrupt' at t1.rb:2 - Exception RuntimeError' at t1.rb:6 - in ensure
Exception RuntimeError' at <main>:0 - in ensure t1.rb:2:in join': Interrupt
from t1.rb:2:in `'

% ruby-trunk -v t1.rb
ruby 1.9.2dev (2010-01-05 trunk 26241) [x86_64-linux]
Exception Interrupt' at t1.rb:2 - Exception RuntimeError' at t1.rb:6 - in ensure
Exception RuntimeError' at t1.rb:0 - in ensure t1.rb:2:in join': Interrupt
from t1.rb:2:in `'

%
=end

[rogerdpack (Roger Pack)]

=begin
looks like it's still erring
=end

[wanabe (_ wanabe)]

=begin
この現象について調べて見ました。すみません、うまく纏められず長い説明になります。

まずはじめに、シグナルを処理するスレッドは 1.8 ではカレント、1.9 ではメインと異なっています。
このため、> start ではなく join になっている　の部分は仕様変更によるものと考えられます。
（行番号は 6 のほうが親切な気もしますが、とりあえず本チケットとは無関係と考えます）

それから一番の問題である行番号が 0 になる現象についてです。
Ruby プロセスが終了するときには、子スレッド各々の ensure 節を実行しますが
この中でさらに例外が発生すると $DEBUG = true ならばメインスレッドまで伝播させようとします。
しかしメインスレッドはすでにクリーンアップ処理中で、トップフレーム以外は積まれておらず
そのために行番号が 0 と判断される、ということのようでした。

対策として
・そういうものとして割り切る（仕様変更とする）
・プロセス終了処理中のメインスレッドでの例外は表示しない
・プロセス終了処理中はメインスレッドへ例外を伝播させない
・トップフレームでの例外は表示しない
といったものを考えましたが、どうするのが最適かは私にはわかりません。
=end

[mame (Yusuke Endoh)]

=begin
遠藤です。

この現象について調べて見ました。

ありがとうございます。

対策として
・そういうものとして割り切る（仕様変更とする）
・プロセス終了処理中のメインスレッドでの例外は表示しない
・プロセス終了処理中はメインスレッドへ例外を伝播させない
・トップフレームでの例外は表示しない
といったものを考えましたが、どうするのが最適かは私にはわかりません。

個人的にはどれでもいいと思います。
別の候補として、0 だったら行番号だけ省略するパッチを書いてみました。
慎重さを要する懸案ではないと思うので、さっさと直してしまいたいと思います。

$ git diff eval.c
diff --git a/eval.c b/eval.c
index 6deed9c..a1deab6 100644
--- a/eval.c
+++ b/eval.c
@@ -394,11 +394,16 @@ setup_exception(rb_thread_t *th, int tag, volatile VALUE mesg)
PUSH_TAG();
if ((status = EXEC_TAG()) == 0) {
RB_GC_GUARD(e) = rb_obj_as_string(e);

•       if (file) {
  

•       if (file && line) {
            warn_printf("Exception `%s' at %s:%d - %s\n",
                        rb_obj_classname(th->errinfo),
                        file, line, RSTRING_PTR(e));
        }
  

•       else if (file) {
  

•           warn_printf("Exception `%s' at %s - %s\n",
  

•                       rb_obj_classname(th->errinfo),
  

•                       file, RSTRING_PTR(e));
  

•       }
        else {
            warn_printf("Exception `%s' - %s\n",
                        rb_obj_classname(th->errinfo),
  

$ cat t.rb
$DEBUG = true
Thread.start do
begin
Process.kill(:INT, $$)
ensure
raise
end
end.join

$ ./miniruby t.rb
Exception Interrupt' at t.rb:2 - Exception RuntimeError' at t.rb:6 -
Exception RuntimeError' at t.rb - t.rb:2:in join': Interrupt
from t.rb:2:in `'

--
Yusuke Endoh [e-mail]
=end

[mame (Yusuke Endoh)]

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

=begin
This issue was solved with changeset r26817.
Kazuhiro, thank you for reporting this issue.
Your contribution to Ruby is greatly appreciated.
May Ruby be with you.

=end