Call plus ensure does not properly initialize all temps #3969

Closed
headius opened this Issue Jun 15, 2016 · 8 comments

Comments

Projects
None yet
2 participants
@headius
Member

headius commented Jun 15, 2016

Environment

JRuby master as of today.

Expected Behavior

@subbuss added a pass to only initialize variables (to nil) that would not otherwise be initialized before they need to be read.

Actual Behavior

The pass in question does not appear to be handling some cases correctly. The following fails to compile in JIT because there are uninitialized variables:

Caused by: java.lang.VerifyError: Bad local variable type
Exception Details:
  Location:
    blah.RUBY$method$raw$0(Lorg/jruby/runtime/ThreadContext;Lorg/jruby/parser/StaticScope;Lorg/jruby/runtime/builtin/IRubyObject;[Lorg/jruby/runtime/builtin/IRubyObject;Lorg/jruby/runtime/Block;Lorg/jruby/RubyModule;Ljava/lang/String;)Lorg/jruby/runtime/builtin/IRubyObject; @89: aload
  Reason:
    Type top (current frame, locals[10]) is not assignable to reference type
  Current Frame:
    bci: @89
    flags: { }
    locals: { 'org/jruby/runtime/ThreadContext', 'org/jruby/parser/StaticScope', 'org/jruby/runtime/builtin/IRubyObject', '[Lorg/jruby/runtime/builtin/IRubyObject;', 'org/jruby/runtime/Block', 'org/jruby/RubyModule', 'java/lang/String', top, 'org/jruby/runtime/builtin/IRubyObject', 'org/jruby/runtime/builtin/IRubyObject', top, top, top, 'java/lang/Throwable', 'org/jruby/runtime/builtin/IRubyObject' }
    stack: { 'org/jruby/runtime/ThreadContext', 'org/jruby/runtime/builtin/IRubyObject', 'org/jruby/runtime/builtin/IRubyObject' }

I believe this fails to verify because the JVM knows that calls can raise exceptions, and with an ensure block it might branch to code that reads the saved value before it is written. Unfortunately, the following patch seems to break something (though it does seem to help):

diff --git a/core/src/main/java/org/jruby/ir/dataflow/analyses/DefinedVariableNode.java b/core/src/main/java/org/jruby/ir/dataflow/analyses/DefinedVariableNode.java
index 2098b34..c07647d 100644
--- a/core/src/main/java/org/jruby/ir/dataflow/analyses/DefinedVariableNode.java
+++ b/core/src/main/java/org/jruby/ir/dataflow/analyses/DefinedVariableNode.java
@@ -97,7 +97,7 @@ public class DefinedVariableNode extends FlowGraphNode<DefinedVariablesProblem,
                         tmp.set(problem.getDFVar(v));
                     }

-                    if (!tmp.get(problem.getDFVar(v))) {
+                    if (!tmp.get(problem.getDFVar(v)) || i.getOperation().canRaiseException()) {
                         // System.out.println("Variable " + v + " in instr " + i + " in " + basicBlock + " isn't defined!");
                         undefinedVars.add(v);
                     }

When I apply this patch and try to run with -X+C (force compile on load) I get the following output:

$ jruby -Xjit.logging -Xjit.logging.verbose -X+C -e 1
2016-06-14T19:36:12.234-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/java.rb
2016-06-14T19:36:12.313-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/java/java_utilities.rb
2016-06-14T19:36:12.322-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/java/core_ext.rb
2016-06-14T19:36:12.398-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/java/core_ext/module.rb
2016-06-14T19:36:12.468-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/java/core_ext/object.rb
2016-06-14T19:36:12.474-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/java/java_ext.rb
2016-06-14T19:36:12.579-05:00 [main] INFO Ruby : done compiling target script: file:/Users/headius/projects/jruby/lib/jruby.jar!/jruby/jruby.rb
2016-06-14T19:36:12.658-05:00 [main] INFO Ruby : done compiling target script: file:/Users/headius/projects/jruby/lib/jruby.jar!/jruby/kernel.rb
2016-06-14T19:36:12.683-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/jruby/type.rb
2016-06-14T19:36:12.726-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/signal.rb
2016-06-14T19:36:12.795-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/kernel.rb
2016-06-14T19:36:12.824-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/proc.rb
2016-06-14T19:36:12.838-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/process.rb
2016-06-14T19:36:12.861-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/jruby/process_util.rb
2016-06-14T19:36:12.886-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/jruby/type.rb
2016-06-14T19:36:13.039-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/enumerator.rb
2016-06-14T19:36:13.113-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/enumerable.rb
2016-06-14T19:36:13.133-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/io.rb
2016-06-14T19:36:13.149-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/time.rb
2016-06-14T19:36:13.251-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/gc.rb
2016-06-14T19:36:13.292-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/range.rb
2016-06-14T19:36:13.298-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/load_error.rb
2016-06-14T19:36:13.345-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/file.rb
2016-06-14T19:36:13.354-05:00 [main] INFO Ruby : done compiling target script: file:/Users/headius/projects/jruby/lib/jruby.jar!/jruby/preludes.rb
2016-06-14T19:36:13.363-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/prelude.rb
2016-06-14T19:36:13.369-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/enc_prelude.rb
2016-06-14T19:36:13.382-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/unicode_normalize.rb
2016-06-14T19:36:13.391-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/gem_prelude.rb
2016-06-14T19:36:13.652-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems.rb
2016-06-14T19:36:13.667-05:00 [main] INFO Ruby : done compiling target script: uri:classloader:/jruby/kernel/rbconfig.rb
2016-06-14T19:36:13.682-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/compatibility.rb
2016-06-14T19:36:13.723-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/defaults.rb
2016-06-14T19:36:13.745-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/deprecate.rb
2016-06-14T19:36:13.778-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/errors.rb
2016-06-14T19:36:14.437-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/specification.rb
2016-06-14T19:36:14.488-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/version.rb
2016-06-14T19:36:14.568-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/requirement.rb
2016-06-14T19:36:14.650-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/platform.rb
2016-06-14T19:36:14.699-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/basic_specification.rb
2016-06-14T19:36:14.742-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/stub_specification.rb
2016-06-14T19:36:14.758-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/util/list.rb
2016-06-14T19:36:14.888-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/exceptions.rb
2016-06-14T19:36:15.043-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/defaults/jruby.rb
2016-06-14T19:36:15.123-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/config_file.rb
2016-06-14T19:36:15.198-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/user_interaction.rb
2016-06-14T19:36:15.222-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/util.rb
2016-06-14T19:36:15.300-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/io/console.rb
2016-06-14T19:36:15.323-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/io/bsd_console.rb
2016-06-14T19:36:15.325-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/ffi.rb
2016-06-14T19:36:15.354-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/ffi/ffi.rb
2016-06-14T19:36:15.428-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/ffi/platform.rb
2016-06-14T19:36:15.453-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/ffi/types.rb
2016-06-14T19:36:15.613-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/jar_install_post_install_hook.rb
2016-06-14T19:36:15.619-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/jars/post_install_hook.rb
2016-06-14T19:36:15.728-05:00 [main] INFO Ruby : done compiling target script: /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/dependency.rb
TypeError: wrong argument type NilClass (expected Regexp)
                            sub! at org/jruby/RubyString.java:2383
                             sub at org/jruby/RubyString.java:2358
  block in register_default_spec at /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems.rb:1188
                            each at org/jruby/RubyArray.java:1593
           register_default_spec at /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems.rb:1186
          block in load_defaults at /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/specification.rb:874
              block in each_spec at /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/specification.rb:821
           block in each_gemspec at /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/specification.rb:743
                            each at org/jruby/RubyArray.java:1593
           block in each_gemspec at /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/specification.rb:742
                            each at org/jruby/RubyArray.java:1593
                    each_gemspec at /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/specification.rb:741
                       each_spec at /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/specification.rb:819
                   load_defaults at /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems/specification.rb:871
                           <top> at /Users/headius/projects/jruby/lib/ruby/stdlib/rubygems.rb:1321
                         require at org/jruby/RubyKernel.java:942
                           <top> at uri:classloader:/jruby/kernel/gem_prelude.rb:3
                            load at org/jruby/RubyKernel.java:960
                           <top> at file:/Users/headius/projects/jruby/lib/jruby.jar!/jruby/preludes.rb:4

@subbuss Is my patch wrong?

@headius headius added this to the JRuby 9.1.3.0 milestone Jun 15, 2016

@subbuss

This comment has been minimized.

Show comment
Hide comment
@subbuss

subbuss Jun 15, 2016

Contributor

Can you paste a ruby snippet to help me debug this? This might actually be as simple as the CFG missing some exception edges ... Tom and I had talked about them long back and I haven't kept track whether those got added or not.

Contributor

subbuss commented Jun 15, 2016

Can you paste a ruby snippet to help me debug this? This might actually be as simple as the CFG missing some exception edges ... Tom and I had talked about them long back and I haven't kept track whether those got added or not.

@subbuss

This comment has been minimized.

Show comment
Hide comment
@subbuss

subbuss Jun 15, 2016

Contributor

As for your patch, we don't want to force all vars that are defined by an exception-throwing instruction to be undefined. That is unnecessarily conservative .. Ex: "a = 1; .... a = some_call(...) ... " No need to treat 'a' as undefined.

Contributor

subbuss commented Jun 15, 2016

As for your patch, we don't want to force all vars that are defined by an exception-throwing instruction to be undefined. That is unnecessarily conservative .. Ex: "a = 1; .... a = some_call(...) ... " No need to treat 'a' as undefined.

@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Jun 15, 2016

Member

Ahh good point about variables that were already initialized...that's probably why this broke, it assigned nil to something already holding a program value.

Here's the Ruby code:

def foo
  saved = bar()
ensure
  bar(saved)
end

def bar(saved = nil); 1; end
Member

headius commented Jun 15, 2016

Ahh good point about variables that were already initialized...that's probably why this broke, it assigned nil to something already holding a program value.

Here's the Ruby code:

def foo
  saved = bar()
ensure
  bar(saved)
end

def bar(saved = nil); 1; end
@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Jun 15, 2016

Member

I've taken a couple stabs at it and haven't come up with a patch. I thought guarding both of the i instanceof ResultInstr would do it, but then it encounters a subsequent copy and considers that an assignment. I'll keep fiddling with it for a bit.

Member

headius commented Jun 15, 2016

I've taken a couple stabs at it and haven't come up with a patch. I thought guarding both of the i instanceof ResultInstr would do it, but then it encounters a subsequent copy and considers that an assignment. I'll keep fiddling with it for a bit.

@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Jun 15, 2016

Member

Here's what I've got...it still doesn't work even though I stepped through the DefinedVariablesProblem and saw it add the correct variable to the undefined list...

diff --git a/core/src/main/java/org/jruby/ir/dataflow/analyses/DefinedVariableNode.java b/core/src/main/java/org/jruby/ir/dataflow/analyses/DefinedVariableNode.java
index 2098b34..819545c2 100644
--- a/core/src/main/java/org/jruby/ir/dataflow/analyses/DefinedVariableNode.java
+++ b/core/src/main/java/org/jruby/ir/dataflow/analyses/DefinedVariableNode.java
@@ -66,7 +66,7 @@ public class DefinedVariableNode extends FlowGraphNode<DefinedVariablesProblem,
     @Override
     public void applyTransferFunction(Instr i) {
         // v is defined
-        if (i instanceof ResultInstr) {
+        if (i instanceof ResultInstr && !i.getOperation().canRaiseException()) {
             tmp.set(problem.getDFVar(((ResultInstr) i).getResult()));
         }

@@ -105,7 +105,7 @@ public class DefinedVariableNode extends FlowGraphNode<DefinedVariablesProblem,
             }

             // v is defined
-            if (i instanceof ResultInstr) {
+            if (i instanceof ResultInstr && !i.getOperation().canRaiseException()) {
                 tmp.set(problem.getDFVar(((ResultInstr) i).getResult()));
             }
         }
Member

headius commented Jun 15, 2016

Here's what I've got...it still doesn't work even though I stepped through the DefinedVariablesProblem and saw it add the correct variable to the undefined list...

diff --git a/core/src/main/java/org/jruby/ir/dataflow/analyses/DefinedVariableNode.java b/core/src/main/java/org/jruby/ir/dataflow/analyses/DefinedVariableNode.java
index 2098b34..819545c2 100644
--- a/core/src/main/java/org/jruby/ir/dataflow/analyses/DefinedVariableNode.java
+++ b/core/src/main/java/org/jruby/ir/dataflow/analyses/DefinedVariableNode.java
@@ -66,7 +66,7 @@ public class DefinedVariableNode extends FlowGraphNode<DefinedVariablesProblem,
     @Override
     public void applyTransferFunction(Instr i) {
         // v is defined
-        if (i instanceof ResultInstr) {
+        if (i instanceof ResultInstr && !i.getOperation().canRaiseException()) {
             tmp.set(problem.getDFVar(((ResultInstr) i).getResult()));
         }

@@ -105,7 +105,7 @@ public class DefinedVariableNode extends FlowGraphNode<DefinedVariablesProblem,
             }

             // v is defined
-            if (i instanceof ResultInstr) {
+            if (i instanceof ResultInstr && !i.getOperation().canRaiseException()) {
                 tmp.set(problem.getDFVar(((ResultInstr) i).getResult()));
             }
         }
@subbuss

This comment has been minimized.

Show comment
Hide comment
@subbuss

subbuss Jun 15, 2016

Contributor

I am going to take a look at it now ... the fix is mostly to fix how state is initialized for blocks that are rescue handlers. They need to receive state from the start of all BBs (rather than end of all BBs) that can fall into the rescue block. There are multiple ways of doing that. Either fixing the DataflowProblem generic solution to fix the MEET operation, do it on a case-by-case basis for each problem, or by adding appropriate dummy CFG edges to get the same effect.

Contributor

subbuss commented Jun 15, 2016

I am going to take a look at it now ... the fix is mostly to fix how state is initialized for blocks that are rescue handlers. They need to receive state from the start of all BBs (rather than end of all BBs) that can fall into the rescue block. There are multiple ways of doing that. Either fixing the DataflowProblem generic solution to fix the MEET operation, do it on a case-by-case basis for each problem, or by adding appropriate dummy CFG edges to get the same effect.

@subbuss

This comment has been minimized.

Show comment
Hide comment
@subbuss

subbuss Jun 15, 2016

Contributor

I can explain how this all set up in person if you want to meet up sometime. /cc @enebo

Contributor

subbuss commented Jun 15, 2016

I can explain how this all set up in person if you want to meet up sometime. /cc @enebo

@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Jun 15, 2016

Member

It would be good to meet up this week. I'm going out of town for a week and will have time to hack around while on vacation.

Member

headius commented Jun 15, 2016

It would be good to meet up this week. I'm going out of town for a week and will have time to hack around while on vacation.

@subbuss subbuss closed this in f3f5776 Jun 15, 2016

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment