From: Rocky Bernstein Date: 2010-03-19T04:45:13+09:00 Subject: [ruby-core:28765] Re: When a trace hook raises an exception, should it terminate the program? --001636ed69a80a74810482187800 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Thanks for the information. Sorry for the confusion I caused by describing the wrong behavior and giving a program that promoted that confusion. Yes, JRuby does what is most helpful and what I would expect it to do: raise an error and continue tracing events. Ruby 1.9's behavior looks to me like a bug, because after raising the error it gets itself in a state that prevents further tracing from occurring (except by extraordinary measures like reinstalling the trace hook). I think I know how to fix this in Ruby 1.9, and I will post a bug report an= d patch to redmine. Ruby Specification folks: is there any behavior specified right for what happens when a trace hook raises an error? Are trace hooks considered part of Ruby or not? On Thu, Mar 18, 2010 at 2:37 PM, Charles Oliver Nutter wrote: > On Thu, Mar 18, 2010 at 5:52 AM, Rocky Bernstein > wrote: > > The "sort of" part is that in Ruby 1.9 the implementation of tracing > sets a > > bit in the thread structure which turns off tracing into the tracer (or > > debugging into the debugger). When an exception that passes from hook t= o > > non-hook occurs, this bit doesn't get cleared. > > That doesn't appear to be the case in JRuby. The bit clearing happens > in a Java "finally" block, which runs no matter what happens in the > hook itself. See below. > > > Changing the program that was originally posted will show this better: > > > > s =3D Proc.new { > > |event, file, lineno, mid, binding, klass| > > puts "#{event} #{mid} #{lineno}" > > unless $x > > $x =3D true > > raise RuntimeError > > end > > } > > begin > > set_trace_func(s) > > puts "after trace func" > > rescue > > puts "Rescued" > > end > > puts "After begin" > > > > Run this in Ruby 1.9 and perhaps it is more apparent that the program > > continues to the end. In the original posting if you look carefully > you'll > > see that the rescue did run *after* the trace hook issued a raise insid= e > the > > begin block. It is the *second* raise issued in the hook function that > > terminates the program because the debugged program is no longer in a > > rescue'd block. > > In the JRuby case, for your original script, it seemed to take several > raises for it to terminate. All the trace events appeared to be in the > main body of code, and not inside the trace hook. > > Here's the behavior for the new script in JRuby, which seems to > continue tracing appropriately after the initial raise inside the hook > > ~/projects/jruby =E2=9E=94 jruby --debug hook_thing2.rb > line 11 (first event, causes raise) > c-call =3D=3D=3D 11 (rescue calling =3D=3D=3D) > c-return =3D=3D=3D 11 (=3D=3D=3D returning) > line 13 (inside rescue block) > c-call puts 13 (calling puts) > c-call write 13 (puts calls write) > Rescuedc-return write 13 (write returns) > c-call write 13 (puts calls write again for \n) > > c-return write 13 (write returns) > c-return puts 13 (puts returns) > line 15 (outside rescue block) > c-call puts 15 (calling puts) > c-call write 15 (puts calls write) > After beginc-return write 15 (write returns) > c-call write 15 (puts calls write for \n) > > c-return write 15 (write returns) > c-return puts 15 (puts returns) > > Is this the output you expected? If not, what do you expect? > > > From what you describe from JRuby, it sounds like it has a similar > behavior > > possibly because it is implemented underneath in a similar way. So > > rationalizing this as "this makes sense because this happened in betwee= n > > statements and not in the program" I don't think is accurately capturin= g > > what's going inside either interpreter. > > Your original script could never do anything but terminate because the > hooks just kept re-throwing...or at least they did in JRuby, which > turns tracing back on when the hook is exited, even if it's exited > abnormally (because of an exception). > > - Charlie > > --001636ed69a80a74810482187800 Content-Type: text/html; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Thanks for the information. Sorry for the confusion I caused by describing = the wrong behavior and giving a program that promoted that confusion.
Yes, JRuby does what is most=C2=A0 helpful and what I would expect it to = do: raise an error and continue tracing events. Ruby 1.9's behavior loo= ks to me like a bug, because after raising the error it gets itself in a st= ate that prevents further tracing from occurring (except by extraordinary m= easures like reinstalling the trace hook).

I think I know how to fix this in Ruby 1.9, and I will post a bug repor= t and patch to redmine.

Ruby Specification folks: is there any beha= vior specified right for what happens when a trace hook raises an error?
Are trace hooks considered part of Ruby or not?

On Thu, Mar 18, 2010 at 2:37 PM, Charles Oliver Nutter <headius@headius.com> wrote:
On Thu, Mar 18, 2010 at 5:52 AM, Rocky Bernstein <rockyb@rubyforge.org> wrote:
> The "sort of" part is=C2=A0 that in Ruby 1.9 the implementat= ion of tracing sets a
> bit in the thread structure which turns off tracing into the tracer (o= r
> debugging into the debugger). When an exception that passes from hook = to
> non-hook occurs, this bit doesn't get cleared.

That doesn't appear to be the case in JRuby. The bit clearing hap= pens
in a Java "finally" block, which runs no matter what happens in t= he
hook itself. See below.

> Changing the program that was originally posted will show this better:=
>
> s =3D Proc.new {
> =C2=A0 |event, file, lineno, mid, binding, klass|
> =C2=A0 puts "#{event} #{mid} #{lineno}"
> =C2=A0 unless $x
> =C2=A0=C2=A0=C2=A0 $x =3D true
> =C2=A0=C2=A0=C2=A0 raise RuntimeError
> =C2=A0 end
> }
> begin
> =C2=A0 set_trace_func(s)
> =C2=A0 puts "after trace func"
> rescue
> =C2=A0 puts "Rescued"
> end
> puts "After begin"
>
> Run this in Ruby 1.9 and perhaps it is more apparent that the program<= br> > continues to the end. In the original posting if you look carefully yo= u'll
> see that the rescue did run *after* the trace hook issued a raise insi= de the
> begin block. It is the *second* raise issued in the hook function that=
> terminates the program because the debugged program is no longer in a<= br> > rescue'd block.

In the JRuby case, for your original script, it seemed to take severa= l
raises for it to terminate. All the trace events appeared to be in the
main body of code, and not inside the trace hook.

Here's the behavior for the new script in JRuby, which seems to
continue tracing appropriately after the initial raise inside the hook

~/projects/jruby =E2=9E=94 jruby --debug hook_thing2.rb
line =C2=A011 (first event, causes raise)
c-call =3D=3D=3D 11 (rescue calling =3D=3D=3D)
c-return =3D=3D=3D 11 (=3D=3D=3D returning)
line =C2=A013 (inside rescue block)
c-call puts 13 (calling puts)
c-call write 13 (puts calls write)
Rescuedc-return write 13 (write returns)
c-call write 13 (puts calls write again for \n)

c-return write 13 (write returns)
c-return puts 13 (puts returns)
line =C2=A015 (outside rescue block)
c-call puts 15 (calling puts)
c-call write 15 (puts calls write)
After beginc-return write 15 (write returns)
c-call write 15 (puts calls write for \n)

c-return write 15 (write returns)
c-return puts 15 (puts returns)

Is this the output you expected? If not, what do you expect?

> From what you describe from JRuby, it sounds like it has a similar beh= avior
> possibly because it is implemented underneath in a similar way. So
> rationalizing this as "this makes sense because this happened in = between
> statements and not in the program" I don't think is accuratel= y capturing
> what's going inside either interpreter.

Your original script could never do anything but terminate because th= e
hooks just kept re-throwing...or at least they did in JRuby, which
turns tracing back on when the hook is exited, even if it's exited
abnormally (because of an exception).

- Charlie


--001636ed69a80a74810482187800--