Bug #1954

line number 0?

Added by znz (Kazuhiro NISHIYAMA) almost 3 years ago. Updated about 1 year ago.

[ruby-dev:39116]
Status:Closed Start date:08/19/2009
Priority:Normal Due date:
Assignee:ko1 (Koichi Sasada) % Done:

100%

Category:core
Target version:1.9.2
ruby -v:ruby 1.9.2dev (2009-08-18 trunk 24578) [i686-linux]

Description

$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 `<main>'

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

Associated revisions

Revision 26244
Added by znz (Kazuhiro NISHIYAMA) over 2 years ago

* test/ruby/test_exception.rb: add a test. cf [ruby-dev:39116]

Revision 26817
Added by mame (Yusuke Endoh) about 2 years ago

* eval.c (setup_exception): avoid line number 0 when setting $DEBUG=true. [ruby-dev:39116]

History

Updated by yugui (Yuki Sonoda) over 2 years ago

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

Updated by rogerdpack (Roger Pack) over 2 years ago

Is this still the case, at all?
-r

Updated by znz (Kazuhiro NISHIYAMA) over 2 years ago

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

他のバージョンと挙動を比べてみると
* REE: "in ensure" が出てこない
* 1.9.1: <main>: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 `<main>'

% 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 `<main>'

%

Updated by rogerdpack (Roger Pack) over 2 years ago

looks like it's still erring

Updated by wanabe (_ wanabe) over 2 years ago

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

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

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

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

Updated by mame (Yusuke Endoh) about 2 years ago

遠藤です。

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

ありがとうございます。


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

個人的にはどれでもいいと思います。
別の候補として、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 `<main>'

-- 
Yusuke Endoh <mame@tsg.ne.jp>

Updated by mame (Yusuke Endoh) about 2 years ago

  • Status changed from Assigned to Closed
  • % Done changed from 0 to 100
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.

Also available in: Atom PDF