Openj9: Wrong behavior on nashorn

[pmlopes]

Consider the following script:

function x() {
  print(arguments.length);
}
x('a', 'b', 'c');

The expected result is 3. This is the case on:

• nashorn on OpenJDK
• nodejs
• any browser
• GraalJS

However the OpenJ9 nashorn from OpenJDK11U-jdk_x64_linux_openj9_linuxXL-jdk-11.0.1.13_openj9-0.11.0_11.0.1_13.tar.gz yields the result 1. Which is clearly wrong.

[pmlopes]

a quick reproducer is to run the script above on jjs and see the result 1 instead of expected 3.

[avermeer]

Hello,

We've got similar issue with AdoptOpenJDK 11 with EclipseJ9 (jdk-11.0.1+13), with the following example, ran with 'jjs':

var tst = function (str) {
    print('typeof str: ' + (typeof str));
    print('str: ' + (str));
    print(arguments.length);
};
tst("some string", 2);

This prints out:

typeof str: object
str: [Ljava.lang.Object;@cc68d3a1
1

While it should print:

typeof str: string
str: some string
2

2 issues are visible:

• The string is turned into a Java Array of Object. It seems to be triggered by the usage of the variable arguments. If I remove the last line, the problem goes away: the string is correctly seen as a string.
• The value of arguments.length is wrong

IMPORTANT: with AdoptOpenJDK 11 with HotSpot (jdk-11.0.1+13), this sample works well.

So it is really an OpenJ9 specific issue.
Can this be fixed in next OpenJ9 release?

Kind regards,
Alexandre

[DanHeidinga]

@ChengJin01 Can you take a look at this?

[ChengJin01]

Will investigate to see what happened to our code.

[ChengJin01]

I tried the test (printing the arguments.length) above with the latest nightly build on Java 8 and Java 11 as follows:

$ jdk8u192_b12_openj9/bin/jjs   arglen.js
3  <---- correct
$ jdk_11.0.1_13_openj9/bin/jjs   arglen.js
Warning: The jjs tool is planned to be removed from a future JDK release
1 <----- wrong

It seems Java 8 works good while Java 11 fails to generate the correct result

Looking at the generated bytecode in
Script$Recompilation$1$13AAA$arglen.zip

public class jdk.nashorn.internal.scripts.Script$Recompilation$1$13AAA$arglen extends jdk.nashorn.internal.scripts.JS
  minor version: 0
  major version: 51
  flags: ACC_PUBLIC, ACC_SUPER
Constant pool:
   #1 = Utf8               jdk/nashorn/internal/scripts/Script$Recompilation$1$13AAA$arglen
   #2 = Class              #1             // jdk/nashorn/internal/scripts/Script$Recompilation$1$13AAA$arglen
   ...
{
  ...
  public static java.lang.Object x(jdk.nashorn.internal.runtime.ScriptFunction, java.lang.Object, java.lang.Object...);
    descriptor: (Ljdk/nashorn/internal/runtime/ScriptFunction;Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;
    flags: ACC_PUBLIC, ACC_STATIC, ACC_VARARGS
    Code:
      stack=3, locals=6, args_size=3
         0: aload_0
         1: invokevirtual #20                 // Method jdk/nashorn/internal/runtime/ScriptFunction.getScope:()Ljdk/nashorn/internal/runtime/ScriptObject;
         4: astore        5
         6: aload_2
         7: aload_0
         8: iconst_0
         9: invokestatic  #26                 // Method jdk/nashorn/internal/objects/Global.allocateArguments:([Ljava/lang/Object;Ljava/lang/Object;I)Ljdk/nashorn/internal/runtime/ScriptObject;
        12: astore_3
        13: aload_3
        14: astore        4
        16: aload         5
        18: invokedynamic #38,  0             // InvokeDynamic #0:"dyn:getMethod|getProp|getElem:print":(Ljava/lang/Object;)Ljava/lang/Object;
        23: getstatic     #44                 // Field jdk/nashorn/internal/runtime/ScriptRuntime.UNDEFINED:Ljdk/nashorn/internal/runtime/Undefined;
        26: aload         4
-----> 28: invokedynamic #47,  0             // InvokeDynamic #1:"dyn:getProp|getElem|getMethod:length":(Ljava/lang/Object;)Ljava/lang/Object;
        33: invokedynamic #51,  0             // InvokeDynamic #0:"dyn:call:print":(Ljava/lang/Object;Ljdk/nashorn/internal/runtime/Undefined;Ljava/lang/Object;)Ljava/lang/Object;
        38: pop
        39: getstatic     #44                 // Field jdk/nashorn/internal/runtime/ScriptRuntime.UNDEFINED:Ljdk/nashorn/internal/runtime/Undefined;
        42: areturn
      LocalVariableTable:
        Start  Length  Slot  Name   Signature
            0      43     0 :callee   Ljdk/nashorn/internal/runtime/ScriptFunction;
            0      43     1 :this   Ljava/lang/Object;
            0      43     2 :varargs   [Ljava/lang/Object;
           12      31     3 :arguments   Ljdk/nashorn/internal/runtime/ScriptObject;
           14      29     4 arguments   Ljava/lang/Object;
            4      39     5 :scope   Ljdk/nashorn/internal/runtime/ScriptObject;

I suspect something wrong happened in dealing with invokedynamic at index 28

-----> 28: invokedynamic #47,  0             // InvokeDynamic #1:"dyn:getProp|getElem|getMethod:length":(Ljava/lang/Object;)Ljava/lang/Object;

Given that Java 8 & 11 share the same code in resolveInvokeDynamic() at /jcl/src/java.base/share/classes/java/lang/invoke/MethodHandle.java, I need to figure out what changes made the behavior different on Java 8 and 11.

[ChengJin01]

I didn't spot any fundamental difference in our code following the calling path of invokeDynamic from the native to jcl against the generated code of the test above.
bytecode_arglen_jdk8.zip
bytecode_arglen_jdk11.zip

So I changed to the test code to:

function x() {
  print("arg.length = " + arguments.length);
  print("arg[0] = " + arguments[0]);
  print("arg[1] = " + arguments[1]);
  print("arg[2] = " + arguments[2]);
  print("arg1.length = " + arguments[0].length);

  print("arg1[0] = " + arguments[0][0]);
  print("arg1[1] = " + arguments[0][1]);
  print("arg1[2] = " + arguments[0][2]);
}
x('a', 'b', 'c');

and the results on Java8/OpenJ9, Java11/Hotspot and Java11/OpenJ9 are as follows:

Java8/OpenJ9:(correct)
# jdk8u192-b12_openj9-0.11.0/bin/jjs   arglen_v1.js
arg.length = 3
arg[0] = a
arg[1] = b
arg[2] = c
arg1.length = 1
arg1[0] = a
arg1[1] = undefined
arg1[2] = undefined

Java11/Hotspot:(correct)
# jdk_11.0.1_13_hotspot/bin/jjs   arglen_v1.js
Warning: The jjs tool is planned to be removed from a future JDK release
arg.length = 3
arg[0] = a
arg[1] = b
arg[2] = c
arg1.length = 1
arg1[0] = a
arg1[1] = undefined
arg1[2] = undefined

Java11/OpenJ9: (correct)
# jdk11_openj9/bin/jjs   arglen_v1.js
Warning: The jjs tool is planned to be removed from a future JDK release
arg.length = 3
arg[0] = a
arg[1] = b
arg[2] = c
arg1.length = 1
arg1[0] = a
arg1[1] = undefined
arg1[2] = undefined

If change the following line:

 print("arg.length = " + arguments.length);

to

 print(arguments.length);

The results on Java11/OpenJ9 are:

# jdk11_openj9/bin/jjs   arglen_v1.js
Warning: The jjs tool is planned to be removed from a future JDK release
1
arg[0] = [Ljava.lang.Object;@973427f
arg[1] = undefined
arg[2] = undefined
arg1.length = 3
arg1[0] = a
arg1[1] = b
arg1[2] = c

That means the passed-in arguments were somehow converted to an array of Object which was stored as the 1th argument in the argument array when printing "arguments.length".

Need to check how the argument array as well as its length is handled in OpenJDK11 and OpenJ9.

[ChengJin01]

Unlike OpenJDK8/OpenJ9, makeConcatWithConstants(the bootstrap method in OpenJDK11) was triggered a bunch of times after setting up the function "x" with invokedynamic in OpenJDK11/Openj9 according to the printing messages added in resolveInvokeDynamic().

In addition, it seems VarargsCollectorHandle is irrelevant to this issue as VarargsCollectorHandle was invoked whether arguments.length was correctly printed out or not.

The next step is to check whether there is any connection between makeConcatWithConstants and arguments.length.

[ChengJin01]

As mentioned before, print("" + arguments.length) outputs the correct number of passed arguments while print(arguments.length) always ends up with 1.

The reason is that the generated bytecode at runtime is a little bit different for x() as follows:
[1] print("" + arguments.length)
public static transient varargs x(ScriptFunction;Object;[Object;)Object;
L0 [bci=0]
0 aload 0
1 invokevirtual ScriptFunction.getScope()ScriptObject;
...
[2] print(arguments.length)
public static transient varargs x(ScriptFunction;Object;[Object;)Object;
try L0 L1 L2 UnwarrantedOptimismException <------------- generated by OpenJDK11
L3 [bci=0]
0 aload 0
1 invokevirtual ScriptFunction.getScope()ScriptObject;

In such case, adding UnwarrantedOptimismException will trigger MethodHandles.catchException(), which eventually invokes asCollector() in buildTransformHandle().

java.lang.Exception
    at java.lang.invoke.MethodHandles.catchException(java.base@11-internal/MethodHandles.java:1961)
    at jdk.nashorn.internal.lookup.MethodHandleFactory$StandardMethodHandleFunctionality.catchException(jdk.scripting.nashorn@11-internal/MethodHandleFactory.java:461)
    at jdk.nashorn.internal.runtime.CompiledFunction.createInvoker(jdk.scripting.nashorn@11-internal/CompiledFunction.java:733)
    at jdk.nashorn.internal.runtime.CompiledFunction.access$200(jdk.scripting.nashorn@11-internal/CompiledFunction.java:63)
    at jdk.nashorn.internal.runtime.CompiledFunction$2.get(jdk.scripting.nashorn@11-internal/CompiledFunction.java:681)
    at jdk.nashorn.internal.runtime.CompiledFunction$2.get(jdk.scripting.nashorn@11-internal/CompiledFunction.java:678)
    at jdk.nashorn.internal.runtime.CompiledFunction.getValidOptimisticInvocation(jdk.scripting.nashorn@11-internal/CompiledFunction.java:624)
    at jdk.nashorn.internal.runtime.CompiledFunction.createFunctionInvocation(jdk.scripting.nashorn@11-internal/CompiledFunction.java:678)
    at jdk.nashorn.internal.runtime.ScriptFunction.findCallMethod(jdk.scripting.nashorn@11-internal/ScriptFunction.java:949)
    at jdk.nashorn.internal.runtime.ScriptObject.lookup(jdk.scripting.nashorn@11-internal/ScriptObject.java:1880)
    at jdk.nashorn.internal.runtime.linker.NashornLinker.getGuardedInvocation(jdk.scripting.nashorn@11-internal/NashornLinker.java:104)
    at jdk.nashorn.internal.runtime.linker.NashornLinker.getGuardedInvocation(jdk.scripting.nashorn@11-internal/NashornLinker.java:96)
    at jdk.dynalink.linker.support.CompositeTypeBasedGuardingDynamicLinker.getGuardedInvocation(jdk.dynalink@11-internal/CompositeTypeBasedGuardingDynamicLinker.java:161)
    at jdk.dynalink.linker.support.CompositeGuardingDynamicLinker.getGuardedInvocation(jdk.dynalink@11-internal/CompositeGuardingDynamicLinker.java:109)
    at jdk.dynalink.LinkerServicesImpl.lambda$getGuardedInvocation$0(jdk.dynalink@11-internal/LinkerServicesImpl.java:137)
    at jdk.dynalink.LinkerServicesImpl$$Lambda$66.000000008C631500.get(Unknown Source)
    at jdk.dynalink.LinkerServicesImpl.getWithLookupInternal(jdk.dynalink@11-internal/LinkerServicesImpl.java:168)
    at jdk.dynalink.LinkerServicesImpl.getGuardedInvocation(jdk.dynalink@11-internal/LinkerServicesImpl.java:135)
    at jdk.dynalink.DynamicLinker.relink(jdk.dynalink@11-internal/DynamicLinker.java:242)
    at jdk.nashorn.internal.scripts.Script$Recompilation$1$arglen_v2.000000008C4658B0.:program(arglen_v2.js:4)
    at jdk.nashorn.internal.runtime.ScriptFunctionData.invoke(jdk.scripting.nashorn@11-internal/ScriptFunctionData.java:664)
    at jdk.nashorn.internal.runtime.ScriptFunction.invoke(jdk.scripting.nashorn@11-internal/ScriptFunction.java:513)
    at jdk.nashorn.internal.runtime.ScriptRuntime.apply(jdk.scripting.nashorn@11-internal/ScriptRuntime.java:527)
    at jdk.nashorn.tools.Shell.apply(jdk.scripting.nashorn@11-internal/Shell.java:522)
    at jdk.nashorn.tools.Shell.runScripts(jdk.scripting.nashorn@11-internal/Shell.java:451)
    at jdk.nashorn.tools.Shell.run(jdk.scripting.nashorn@11-internal/Shell.java:189)
    at jdk.nashorn.tools.jjs.Main.main(jdk.scripting.nashorn.shell@11-internal/Main.java:105)
    at jdk.nashorn.tools.jjs.Main.main(jdk.scripting.nashorn.shell@11-internal/Main.java:81)

    public static MethodHandle catchException(MethodHandle tryHandle, Class<? extends Throwable> throwableClass, MethodHandle catchHandle) throws NullPointerException, IllegalArgumentException{
...
        MethodHandle result = buildTransformHandle(new CatchHelper(tryHandle, catchHandle, throwableClass), tryType);

    private static MethodHandle buildTransformHandle(ArgumentHelper helper, MethodType mtype){
        MethodType helperType = MethodType.methodType(Object.class, Object[].class);
        try {
            return Lookup.internalPrivilegedLookup.bind(helper, "helper", helperType).asCollector(Object[].class, mtype.parameterCount()).asType(mtype); //$NON-NLS-1$
        } catch(IllegalAccessException | NoSuchMethodException e) {
            throw new Error(e);
        }
    }

If so, the reason for the incorrect the argument number is that asCollector already collected the incoming trailing argument to an array argument when generating the requested method handle (catchException won't be triggered without UnwarrantedOptimismException in the bytecode)

Note: catchException() was not triggered in Java 8 as UnwarrantedOptimismException was never generated by OpenJDK8 in any case.

[ChengJin01]

Given that the runtime bytecode generated from the javascript is controlled by OpenJDK11 (which means we might be not allowed to modify the implementation in OpenJDK11 to accommodate our own code in OpenJ9), we might need to consider how to deal with this special case in catchException() (e.g. stop collecting the incoming arguments in the case of javascript-based bytecode).

[pdbain-ibm]

This may be related to
https://github.com/eclipse/openj9/issues/3274

[ChengJin01]

I went over the issue at #3274 against the debugging messages in the javascript code here:

findStatic: clazz = jdk.nashorn.internal.scripts.Script$Recompilation$2$arglen_v2/000000008C466B70
findStatic: methodName = x
findStatic: type.arguments = [class jdk.nashorn.internal.runtime.ScriptFunction, class java.lang.Object, class [Ljava.lang.Object;]
VarargsCollectorHandle: this.arrayType = class [Ljava.lang.Object;
VarargsCollectorHandle: this.isPrimitiveVarargs = true
java.lang.Exception
    at java.lang.invoke.VarargsCollectorHandle.<init>(java.base@11-internal/VarargsCollectorHandle.java:52)
    at java.lang.invoke.PrimitiveHandle.asVarargsCollector(java.base@11-internal/PrimitiveHandle.java:183)
    at java.lang.invoke.MethodHandles$Lookup.convertToVarargsIfRequired(java.base@11-internal/MethodHandles.java:195)
    at java.lang.invoke.MethodHandles$Lookup.findStatic(java.base@11-internal/MethodHandles.java:583)
    at jdk.nashorn.internal.lookup.MethodHandleFactory$StandardMethodHandleFunctionality.findStatic(jdk.scripting.nashorn@11-internal/MethodHandleFactory.java:542)
...

From the test case perspective, it seems they belong to the same problem that the collection operation incorrectly occurred twice for x() during the execution (one via asVarargsCollector for x() and another in catchException via asCollector()).

Need to check the API Spec for asVarargsCollector and catchException to see whether we missed something in the code there to handle this case.

[DanHeidinga]

@ChengJin01 I think #4223 has a fix for this.

[ChengJin01]

Many thanks @DanHeidinga! I already compiled a build with the proposed fix at #4223 and the javascript test works good to output the expected arguments.length. So the issue here can be closed once the fix gets merged.

[avermeer]

Hello and Happy new year!

This is excellent news to read that this issue with Nashorn is fixed.
What would be simplest way to get AdoptOpenJDK 11 binaries (I'm in particular interest in Linux x64 & Windows x64) including this fix?

Kind regards,
Alexandre

[pdbain-ibm]

@avermeer there will be builds with this fix at https://adoptopenjdk.net/nightly.html?variant=openjdk11&jvmVariant=openj9. That may take a day, possibly longer. If you want a build sooner, contact me on openj9.slack.com at @pdbain.

[avermeer]

@pdbain-ibm thank you very much, I can wait until max next Monday, and if it's still not avail on Monday then i'll get in touch with you using slack.

[avermeer]

Hello @pdbain-ibm,

I have downloaded AdoptOpenJDK 11 with OpenJ9 build of the 14 January 2019 from https://adoptopenjdk.net/nightly.html?variant=openjdk11&jvmVariant=openj9, and I confirm that this issue is fixed.

Thank you very much to all who made this fix!

Kind regards,
Alexandre