Details

    • Type: Bug Bug
    • Status: Resolved Resolved
    • Priority: Minor Minor
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: JRuby 1.7.0.pre1
    • Component/s: Extensions
    • Labels:
      None
    • Number of attachments :
      0

      Description

      jruby -rtracer should work like -rtracer...and doesn't appear to..

        Issue Links

          Activity

          Hide
          Charles Oliver Nutter added a comment -

          The problem here is that JRuby doesn't normally support set_trace_func unless you pass --debug, because of the extra overhead that repeatedly checking for trace functions adds to the system. Normally, we warn if set_trace_func is called without being in "full trace mode", but in this case tracer.rb sets verbose to false, disabling all warnings.

          Passing --debug along with -rtracer causes it to work just fine:

          ~/projects/jruby ➔ ruby --debug -rtracer -e "puts 1; puts 2"
          #0:-e:1::-: puts 1; puts 2
          #0:-e:1:Kernel:>: puts 1; puts 2
          #0:-e:1:Fixnum:>: puts 1; puts 2
          #0:-e:1:Fixnum:<: puts 1; puts 2
          #0:-e:1:IO:>: puts 1; puts 2
          1#0:-e:1:IO:<: puts 1; puts 2
          #0:-e:1:IO:>: puts 1; puts 2
          
          #0:-e:1:IO:<: puts 1; puts 2
          #0:-e:1:Kernel:<: puts 1; puts 2
          #0:-e:1::-: puts 1; puts 2
          #0:-e:1:Kernel:>: puts 1; puts 2
          #0:-e:1:Fixnum:>: puts 1; puts 2
          #0:-e:1:Fixnum:<: puts 1; puts 2
          #0:-e:1:IO:>: puts 1; puts 2
          2#0:-e:1:IO:<: puts 1; puts 2
          #0:-e:1:IO:>: puts 1; puts 2
          
          #0:-e:1:IO:<: puts 1; puts 2
          #0:-e:1:Kernel:<: puts 1; puts 2
          

          I'm going to either modify tracer.rb to not turn verbose off or modify set_trace_func to log regardless of verbosity (or raise).

          Show
          Charles Oliver Nutter added a comment - The problem here is that JRuby doesn't normally support set_trace_func unless you pass --debug, because of the extra overhead that repeatedly checking for trace functions adds to the system. Normally, we warn if set_trace_func is called without being in "full trace mode", but in this case tracer.rb sets verbose to false, disabling all warnings. Passing --debug along with -rtracer causes it to work just fine: ~/projects/jruby &#10132; ruby --debug -rtracer -e "puts 1; puts 2" #0:-e:1::-: puts 1; puts 2 #0:-e:1:Kernel:>: puts 1; puts 2 #0:-e:1:Fixnum:>: puts 1; puts 2 #0:-e:1:Fixnum:<: puts 1; puts 2 #0:-e:1:IO:>: puts 1; puts 2 1#0:-e:1:IO:<: puts 1; puts 2 #0:-e:1:IO:>: puts 1; puts 2 #0:-e:1:IO:<: puts 1; puts 2 #0:-e:1:Kernel:<: puts 1; puts 2 #0:-e:1::-: puts 1; puts 2 #0:-e:1:Kernel:>: puts 1; puts 2 #0:-e:1:Fixnum:>: puts 1; puts 2 #0:-e:1:Fixnum:<: puts 1; puts 2 #0:-e:1:IO:>: puts 1; puts 2 2#0:-e:1:IO:<: puts 1; puts 2 #0:-e:1:IO:>: puts 1; puts 2 #0:-e:1:IO:<: puts 1; puts 2 #0:-e:1:Kernel:<: puts 1; puts 2 I'm going to either modify tracer.rb to not turn verbose off or modify set_trace_func to log regardless of verbosity (or raise).
          Hide
          Charles Oliver Nutter added a comment -

          Ok, this actually appears to be a behavioral difference with Kernel#caller. At the toplevel of a required script (from -r) we have a two-deep caller(0) trace. The logic at the bottom of tracer.rb only enables tracing if caller(0) is one-deep at toplevel.

          This is obviously a rather fragile way to know when to turn on tracing, but I have a one-character fix for caller backtrace generation that may be good enough.

          And yes, I realized my example above was still running MRI...

          Show
          Charles Oliver Nutter added a comment - Ok, this actually appears to be a behavioral difference with Kernel#caller. At the toplevel of a required script (from -r) we have a two-deep caller(0) trace. The logic at the bottom of tracer.rb only enables tracing if caller(0) is one-deep at toplevel. This is obviously a rather fragile way to know when to turn on tracing, but I have a one-character fix for caller backtrace generation that may be good enough. And yes, I realized my example above was still running MRI...
          Hide
          Charles Oliver Nutter added a comment -

          I fixed this in 5f3de42 by modifying how we prepare the toplevel binding. Previously, we pushed the frames necessary for toplevel very early, so that TOPLEVEL_BINDING could be constructed. This caused there to be an extra frame already on the stack when doing requires, and so caller(0) had an extra element, and so tracer did not enable itself (or display the tracing warning). The modification in 5f3de42 was to push the context needed for TOPLEVEL_BINDING but then remove them while doing requires, and finally re-init the toplevel context with what it should be for normal execution.

          My previous attempt to fix this-removing an element from all caller(0) traces-caused caller(0) to be incorrect when called from a non -r source, so it was not the right way to go. This fix appears to match MRI a bit better.

          Show
          Charles Oliver Nutter added a comment - I fixed this in 5f3de42 by modifying how we prepare the toplevel binding. Previously, we pushed the frames necessary for toplevel very early, so that TOPLEVEL_BINDING could be constructed. This caused there to be an extra frame already on the stack when doing requires, and so caller(0) had an extra element, and so tracer did not enable itself (or display the tracing warning). The modification in 5f3de42 was to push the context needed for TOPLEVEL_BINDING but then remove them while doing requires, and finally re-init the toplevel context with what it should be for normal execution. My previous attempt to fix this- removing an element from all caller(0) traces -caused caller(0) to be incorrect when called from a non -r source, so it was not the right way to go. This fix appears to match MRI a bit better.
          Hide
          Charles Oliver Nutter added a comment -

          This seemed to cause no end of problems, so I'm reopening it. I reverted the fix in 93b1257 and added a temporary hack to tracer.rb in ecb74ae. We'll need to revisit this for 1.6.

          Show
          Charles Oliver Nutter added a comment - This seemed to cause no end of problems, so I'm reopening it. I reverted the fix in 93b1257 and added a temporary hack to tracer.rb in ecb74ae. We'll need to revisit this for 1.6.
          Hide
          Charles Oliver Nutter added a comment -

          JRUBY-4636 should be confirmed with any fix for this bug.

          Show
          Charles Oliver Nutter added a comment - JRUBY-4636 should be confirmed with any fix for this bug.
          Hide
          Charles Oliver Nutter added a comment -

          Noncritical...moving to 1.7.

          Show
          Charles Oliver Nutter added a comment - Noncritical...moving to 1.7.
          Hide
          Roger Pack added a comment -

          This appears to not work even with --debug these days.

          jruby --debug -rtracer xxx.rb (no tracing output)

          jruby 1.7.0.dev (ruby-1.8.7-p357) (2012-04-09 3391966) (Java HotSpot(TM) Client VM 1.6.0_26) [Windows 7-x86-java]

          Show
          Roger Pack added a comment - This appears to not work even with --debug these days. jruby --debug -rtracer xxx.rb (no tracing output) jruby 1.7.0.dev (ruby-1.8.7-p357) (2012-04-09 3391966) (Java HotSpot(TM) Client VM 1.6.0_26) [Windows 7-x86-java]
          Hide
          Charles Oliver Nutter added a comment -

          Should be fixed by these commits:

          commit daed10cb5d4b2a02edbb670553fbc5c1e314e82a
          Author: Charles Oliver Nutter <headius@headius.com>
          Date:   Thu Apr 12 10:33:36 2012 -0500
          
              Deprecate now-unused ThreadContext.setFile
          
          commit 0b167802678933b8c7346a043287a6210d9bab41
          Author: Charles Oliver Nutter <headius@headius.com>
          Date:   Wed Apr 11 17:32:10 2012 -0500
          
              Fix root-level backtrace mangling caused by old-style logic.
              
              Backtraces are not managed by file and line fields in ThreadContext
              anymore; instead, a new backtrace element should be pushed in each
              case (updating a preallocated stack of BacktraceElement objects).
              The old logic was still being used to set TC.file and TC.line
              before pushing a Frame...a relic from when backtrace data lived on
              Frame and pulled file/line info from the "current" values in TC.
              The continued use of these methods meant that backtrace elements
              were being updated in-place rather than pushed/popped for
              top-level backtraces, mangling them and destroying the proper
              values (ending up showing the last-set filename for toplevel).
              
              This commit removes all uses of setFile/setLine that are not
              performed against a backtrace element owned by the calling
              context.
          
          Show
          Charles Oliver Nutter added a comment - Should be fixed by these commits: commit daed10cb5d4b2a02edbb670553fbc5c1e314e82a Author: Charles Oliver Nutter <headius@headius.com> Date: Thu Apr 12 10:33:36 2012 -0500 Deprecate now-unused ThreadContext.setFile commit 0b167802678933b8c7346a043287a6210d9bab41 Author: Charles Oliver Nutter <headius@headius.com> Date: Wed Apr 11 17:32:10 2012 -0500 Fix root-level backtrace mangling caused by old-style logic. Backtraces are not managed by file and line fields in ThreadContext anymore; instead, a new backtrace element should be pushed in each case (updating a preallocated stack of BacktraceElement objects). The old logic was still being used to set TC.file and TC.line before pushing a Frame...a relic from when backtrace data lived on Frame and pulled file/line info from the "current" values in TC. The continued use of these methods meant that backtrace elements were being updated in-place rather than pushed/popped for top-level backtraces, mangling them and destroying the proper values (ending up showing the last-set filename for toplevel). This commit removes all uses of setFile/setLine that are not performed against a backtrace element owned by the calling context.
          Hide
          Roger Pack added a comment -

          sweet works now.
          thanks!
          roger

          Show
          Roger Pack added a comment - sweet works now. thanks! roger

            People

            • Assignee:
              Charles Oliver Nutter
              Reporter:
              Roger Pack
            • Votes:
              0 Vote for this issue
              Watchers:
              0 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: