Details

    • Number of attachments :
      0

      Description

      The backtrace work is cutting off the Java portion of the trace when calling into Java libraries. This is obviously bad, since it makes debugging Java calls pretty hard.

      ~/projects/jruby ➔ jruby -rjava -e "java.lang.System.get_property(nil)"
      NativeException: java.lang.NullPointerException: key can't be null
        (root) at -e:1
      

        Activity

        Hide
        Charles Oliver Nutter added a comment -

        Ok, I have a conundrum here.

        The new backtrace logic uses the actual Java trace of an exception to build the Ruby trace. However it defaults to excluding frames unless it knows about them, which is why arbitrary Java calls disappear.

        I'm not sure how best to turn off that behavior for subsets of the Java trace. For cases where you simply call from Ruby into Java, it's easy; we just see that there's a marker in the stack indicating we've left Ruby and start aggregating those frames. But then I'm not sure how to handle cases where we call from Java back into Ruby, such as for an interface implementation. There's no clear marker to indicate we're back in "Ruby land" and should start filtering.

        One thought I had would be to default to including frames unless explicitly excluded. So we'd omit any org.jruby stuff that's not a core method, rubyjit.* stuff, rubyobj.* stuff, and packages for any of the libraries we ship. But that might allow too much through, since if we call through a java.* class as part of our internal impl, it will show up in backtraces. The more internal stuff we show in backtraces the more likely we are to screw up anyone expecting caller() to produce similar results to MRI (and I won't get into the politics of why they shouldn't do that).

        A third option would be to have Java exceptions in Ruby land include the Java trace as well, so when they log they log both our Ruby trace and the Java trace that goes with it.

        A fourth option would be to have a clear marker when going from Ruby to Java that turns on full traces, and any call back through org.jruby reenables filtering. This is unlikely to be perfect, but it's closer.

        Show
        Charles Oliver Nutter added a comment - Ok, I have a conundrum here. The new backtrace logic uses the actual Java trace of an exception to build the Ruby trace. However it defaults to excluding frames unless it knows about them, which is why arbitrary Java calls disappear. I'm not sure how best to turn off that behavior for subsets of the Java trace. For cases where you simply call from Ruby into Java, it's easy; we just see that there's a marker in the stack indicating we've left Ruby and start aggregating those frames. But then I'm not sure how to handle cases where we call from Java back into Ruby, such as for an interface implementation. There's no clear marker to indicate we're back in "Ruby land" and should start filtering. One thought I had would be to default to including frames unless explicitly excluded . So we'd omit any org.jruby stuff that's not a core method, rubyjit.* stuff, rubyobj.* stuff, and packages for any of the libraries we ship. But that might allow too much through, since if we call through a java.* class as part of our internal impl, it will show up in backtraces. The more internal stuff we show in backtraces the more likely we are to screw up anyone expecting caller() to produce similar results to MRI (and I won't get into the politics of why they shouldn't do that). A third option would be to have Java exceptions in Ruby land include the Java trace as well, so when they log they log both our Ruby trace and the Java trace that goes with it. A fourth option would be to have a clear marker when going from Ruby to Java that turns on full traces, and any call back through org.jruby reenables filtering. This is unlikely to be perfect, but it's closer.
        Hide
        Charles Oliver Nutter added a comment -

        I've opted not to fix this in 1.6.x, since it is nearing completion and nobody else has reported it. I have applied a reasonably good fix to master; further refinement can occur in 1.7 dev cycle.

        commit 1087192c094ce2e5757faf95859c0da47d6d4d66
        Author: Charles Oliver Nutter <headius@headius.com>
        Date:   Thu Jan 5 14:14:45 2012 -0600
        
            Fix JRUBY-5630: Java calls have lost the Java part of the trace
            
            I fixed this by having normal Ruby traces flip to an "integrated"
            mode when handling JI-sourced exceptions. Integrated mode will
            include all Java frames that aren't org.jruby, sun.reflect, or
            otherwise handled by interpreter/compiler demangling. This allows
            the target Java call's trace to show up at the top of the Ruby
            trace.
            
            This is not quite perfect; I'll need to revisit this in the future
            to make sure we're not allowing too much in. For example, several
            of our shipped libraries will not be filtered, so if they're in
            the trace they'll show up interspersed with Ruby frames. This may
            be rare, however, since almost none of those libraries are call-
            through cases...they're usually leaf code.
        
        Show
        Charles Oliver Nutter added a comment - I've opted not to fix this in 1.6.x, since it is nearing completion and nobody else has reported it. I have applied a reasonably good fix to master; further refinement can occur in 1.7 dev cycle. commit 1087192c094ce2e5757faf95859c0da47d6d4d66 Author: Charles Oliver Nutter <headius@headius.com> Date: Thu Jan 5 14:14:45 2012 -0600 Fix JRUBY-5630: Java calls have lost the Java part of the trace I fixed this by having normal Ruby traces flip to an "integrated" mode when handling JI-sourced exceptions. Integrated mode will include all Java frames that aren't org.jruby, sun.reflect, or otherwise handled by interpreter/compiler demangling. This allows the target Java call's trace to show up at the top of the Ruby trace. This is not quite perfect; I'll need to revisit this in the future to make sure we're not allowing too much in. For example, several of our shipped libraries will not be filtered, so if they're in the trace they'll show up interspersed with Ruby frames. This may be rare, however, since almost none of those libraries are call- through cases...they're usually leaf code.

          People

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

            Dates

            • Created:
              Updated:
              Resolved: