Rick

Rick
Rick

Saturday, October 12, 2013

Java Invoke Dynamic examples (Java 7 invokedynamic) with Benchmarks done on JDK 1.8 (also unsafe, reflection, regular invoke)

This blog is both a how-to and a guide to benchmarks for these technologies.
Reflection is not as slow as you think.
Invoke Dynamic is really fast especially when you use call sites.

I have been messing around with invoke dynamic. I have decided to write my Java utility stuff. I started to write Easy Java which I renamed to Facile, which never made it out of prototype mode. There was a metric ton of code written, but it was all sort of a precursor.
I have a better plan going forward. Part of this plan involved invoke dynamic so... :)

I thought that I better figure out how it works. I pulled a lot of this from the API docs, and just kept messing with it.

Invoke dynamic is only about 2.5 times slower than invoke objects the normal way (last benchmark that I saw). Invoke dynamic is about 15x faster than reflection. I have found that both reflection and invoke dynamic are a lot faster in JDK 1.8. I don't see much differences in tight loops.



At the bottom of the blog is a section about speed/benchmark for invoke dynamic. I compare field access, to method calls, to invoke dynamic.

You can find examples of using reflection, call-sites, invoke dynamic, unsafe field access, and more.



Another update (later that very Sunday)

I changed the code to use a callsite for dynamic invoke and that changed the time quite a bit.

1,000

descriptionduration in nanoseconds
regular method call time 2095
invoke dynamic method call time 1098
reflection method call time 3104
field method invoke dynamic call time 1165
field method invoke reflection call time 689
unsafe field access time 94
direct field access (baseline) 92

10,000

descriptionduration in nanoseconds
regular method call time 68
invoke dynamic method call time 43
reflection method call time 202
field method invoke dynamic call time 42
field method invoke reflection call time 45
unsafe field access time 87
direct 86

100,000

descriptionduration in nanoseconds
regular method call time 70
invoke dynamic method call time 44
reflection method call time 249
field method invoke dynamic call time 45
field method invoke reflection call time 47
unsafe field access time 88
direct 36

1,000,000

descriptionduration in nanoseconds
regular method call time 11
invoke dynamic method call time 6
reflection method call time 12
field method invoke dynamic call time 6
field method invoke reflection call time 4
unsafe field access time 1
direct 0

10,000,000

descriptionduration in nanoseconds
regular method call time 9
invoke dynamic method call time 6
reflection method call time 25
field method invoke dynamic call time 6
field method invoke reflection call time 4
unsafe field access time 1
direct 0

100,000,000

descriptionduration in nanoseconds
regular method call time 9
invoke dynamic method call time 6
reflection method call time 12
field method invoke dynamic call time 6
field method invoke reflection call time 4
unsafe field access time 1
direct 0




Updated code that uses call-site


        //fieldName is the reflection field (example below how to look it up and change its access)
        MethodHandle methodHandleFieldDirect = lookup.unreflectGetter(fieldName);
        CallSite callSiteField = new ConstantCallSite(methodHandleFieldDirect);
        methodHandleFieldDirect = callSiteField.dynamicInvoker();
        name = (String) methodHandleFieldDirect.invokeExact(new Employee());


        //Lookup invoke dynamic
        methodType = MethodType.methodType(String.class);
        methodHandle = lookup.findVirtual(Employee.class, "getName", methodType);
        CallSite callSiteMethod = new ConstantCallSite(methodHandleFieldDirect);
        methodHandle = callSiteMethod.dynamicInvoker();






Below is the run before with using invoke dynamic but not using call sites. You can see that call sites make a big difference in speed.

Update (Sunday night)

1,000

descriptionduration in nanoseconds
regular method call time 2027
invoke dynamic method call time 2475
reflection method call time 2005
field method invoke dynamic call time 1113
field method invoke reflection call time 689
unsafe field access time 104
direct 87

10,000

descriptionduration in nanoseconds
regular method call time 72
invoke dynamic method call time 80
reflection method call time 201
field method invoke dynamic call time 45
field method invoke reflection call time 45
unsafe field access time 84
direct 40

100,000

descriptionduration in nanoseconds
regular method call time 40
invoke dynamic method call time 62
reflection method call time 13
field method invoke dynamic call time 6
field method invoke reflection call time 5
unsafe field access time 2
direct 0

1,000,000

descriptionduration in nanoseconds
regular method call time 14
invoke dynamic method call time 22
reflection method call time 19
field method invoke dynamic call time 5
field method invoke reflection call time 5
unsafe field access time 1
direct 0

10,000,000

descriptionduration in nanoseconds
regular method call time 14
invoke dynamic method call time 25
reflection method call time 21
field method invoke dynamic call time 5
field method invoke reflection call time 5
unsafe field access time 1
direct 0

100,000,000

descriptionduration in nanoseconds
regular method call time 14
invoke dynamic method call time 19
reflection method call time 12
field method invoke dynamic call time 5
field method invoke reflection call time 5
unsafe field access time 1
direct 0


If I run 100,000 runs by itself, I get this:

100,000

descriptionduration in nanoseconds
regular method call time 72
invoke dynamic method call time 82
reflection method call time 215
field method invoke dynamic call time 44
field method invoke reflection call time 46
unsafe field access time 86
direct 42


If I run 100,000,000 runs by itself, I get this.

100,000,000

descriptionduration in nanoseconds
regular method call time 13
invoke dynamic method call time 21
reflection method call time 19
field method invoke dynamic call time 7
field method invoke reflection call time 6
unsafe field access time 2
direct 0


If I run 1,000,000 runs by itself, I get this.

1,000,000

descriptionduration in nanoseconds
regular method call time 16
invoke dynamic method call time 19
reflection method call time 20
field method invoke dynamic call time 8
field method invoke reflection call time 6
unsafe field access time 2
direct 0

Update to benchmark code that includes unsafe

package com.rick;

import sun.misc.Unsafe;

import java.lang.invoke.*;
import java.lang.reflect.Field;
import java.lang.reflect.Method;

public class Benchmarks {

    private static Unsafe getUnsafe() {
        try {
            Field f = Unsafe.class.getDeclaredField("theUnsafe");
            f.setAccessible(true);
            return (Unsafe) f.get(null);
        } catch (Exception e) {
            return null;
        }
    }


    public static class Employee {

        private String name = "Rick";

        public String getName() {
            return name + "##";
        }

        public void setName(String name) {
            this.name = name;
        }

        public String name() {
            return name;
        }

    }

    public static void main(String[] arg) throws Throwable {
        MethodHandles.Lookup lookup = MethodHandles.lookup();
        Class thisClass = lookup.lookupClass();  // (who am I?)
        Employee employee = new Employee();
        Field fieldName = null;
        String name;
        MethodType methodType;
        MethodHandle methodHandle;

        for (Field field : Employee.class.getDeclaredFields()) {
            if (field.getName().equals("name")) {
                fieldName = field;
                fieldName.setAccessible(true);
                break;
            }
        }
        MethodHandle methodHandleFieldDirect = lookup.unreflectGetter(fieldName);
        name = (String) methodHandleFieldDirect.invokeExact(new Employee());
        System.out.println("method handle for field direct " + name);

        //Lookup invoke dynamic
        methodType = MethodType.methodType(String.class);
        methodHandle = lookup.findVirtual(Employee.class, "getName", methodType);
        name = (String) methodHandle.invokeExact(new Employee());
        System.out.println("invoke dynamic " + name);

        //Lookup reflection
        Method method = Employee.class.getMethod("getName", new Class[]{});
        name = (String) method.invoke(new Employee());
        System.out.println("reflection " + name);

        //Now let's be unsafe
        Unsafe unsafe = getUnsafe();
        long offset = unsafe.objectFieldOffset(fieldName);
        name = (String) unsafe.getObject(new Employee(), offset);


        long[] timesArray = {1_000L,
                            10_1000L,
                            100_000L,
                            1_000_000L,
                            10_000_000L,
                            100_000_000L
                                };

        for (long times: timesArray) {
            long start = 0;
            long end = 0;
            long regularTime;
            long invokeDynamicTime;
            long reflectionTime;
            long invokeDynamicTimeUsingField;
            long fieldDirect;
            long unsafeField;
            long direct;

            System.out.printf("

%,d

\n", times); //warm up for (int index =0 ; index < times; index++) { employee.getName(); name = (String) methodHandle.invokeExact(employee); name = (String) method.invoke(employee); name = (String) methodHandleFieldDirect.invokeExact(employee); name = (String) fieldName.get(employee); name = (String) unsafe.getObject(new Employee(), offset); } System.out.printf("\n \n"); start = System.nanoTime(); for (int index =0 ; index < times; index++) { name = employee.getName(); } end = System.nanoTime(); regularTime = end - start; System.out.printf("\n \n" + " \n" + " \n" + " \n" + " \n", regularTime/times); start = System.nanoTime(); for (int index =0 ; index < times; index++) { name = (String) methodHandle.invokeExact(employee); } end = System.nanoTime(); invokeDynamicTime = end - start; System.out.printf("\n \n" + " \n" + " \n" + " \n" + " \n", invokeDynamicTime/times); start = System.nanoTime(); for (int index =0 ; index < times; index++) { name = (String) method.invoke(employee); } end = System.nanoTime(); reflectionTime = end - start; System.out.printf("\n \n" + " \n" + " \n" + " \n" + " \n", reflectionTime/times); start = System.nanoTime(); for (int index =0 ; index < times; index++) { name = (String) methodHandleFieldDirect.invokeExact(employee); } end = System.nanoTime(); invokeDynamicTimeUsingField = end - start; System.out.printf("\n \n" + " \n" + " \n" + " \n" + " \n", invokeDynamicTimeUsingField/times); //old school reflection start = System.nanoTime(); for (int index =0 ; index < times; index++) { name = (String) fieldName.get(employee); } end = System.nanoTime(); fieldDirect = end - start; System.out.printf("\n \n" + " \n" + " \n" + " \n" + " \n", fieldDirect/times); //unsafe refection start = System.nanoTime(); for (int index =0 ; index < times; index++) { name = (String) unsafe.getObject(employee, offset); } end = System.nanoTime(); unsafeField = end - start; System.out.printf("\n \n" + " \n" + " \n" + " \n" + " \n", unsafeField/times); //unsafe refection start = System.nanoTime(); for (int index =0 ; index < times; index++) { name = employee.name; } end = System.nanoTime(); direct = end - start; System.out.printf("\n \n" + " \n" + " \n" + " \n" + " \n", direct/times); System.out.printf("\n \n
descriptionduration in nanoseconds
regular method call time%d
invoke dynamic method call time%d
reflection method call time%d
field method invoke dynamic call time%d
field method invoke reflection call time%d
unsafe field access time%d
direct%d
\n"); } } }

Older runs...

10 million runs with count/hashcode removed employee.getName()

  • regular method call time = 25 nanoseconds
  • invoke dynamic method call time = 18 nanoseconds **
  • reflection method call time = 36 nanoseconds
  • field method invoke dynamic call time = 8 nanoseconds
  • field method reflection call time = 6 nanoseconds

10 thousand runs with count/hashcode removed employee.getName()

  • regular method call time = 70 nanoseconds **
  • invoke dynamic method call time = 84 nanoseconds
  • reflection method call time = 211 nanoseconds
  • field method invoke dynamic call time = 153 nanoseconds
  • field method reflection call time = 40 nanoseconds




package com.rick;

import java.lang.invoke.*;
import java.lang.reflect.Field;
import java.util.List;

public class Invoker {

    public static class Employee {

        private String name = "Rick";

        public String getName() {
            return name + "##";
        }

        public void setName(String name) {
            this.name = name;
        }

        public String name() {
            return name;
        }

    }

    private static MethodHandle printArgs;

    private static void printArgs(Object... args) {
        System.out.println(java.util.Arrays.deepToString(args));
    }


    public static void main(String[] arg) throws Throwable {
        MethodHandles.Lookup lookup = MethodHandles.lookup();
        Class thisClass = lookup.lookupClass();  // (who am I?)


        printArgs = lookup.findStatic(thisClass,
                "printArgs", MethodType.methodType(void.class, Object[].class));

        CallSite callSite = new ConstantCallSite(printArgs);


        printArgs.invoke("Hi Mom!", "Hi World!");

        callSite.dynamicInvoker().invoke("Hi Mom!", "Hi World!");

        CallSite callSite2 = new ConstantCallSite(printArgs.asType(MethodType.methodType(void.class,
                int.class, int.class)));

        try {
            callSite2.dynamicInvoker().invoke("Hi Mom!", "Hi World!");
            throw new AssertionError("Should never get here");
        } catch (WrongMethodTypeException wmte) {

        }

        callSite2.dynamicInvoker().invoke(1, 2);


        MethodType methodType;
        MethodHandle methodHandle;
        String str;
        Object obj;

        //Call a virtual method on String
        // mt is (char,char)String
        methodType = MethodType.methodType(String.class, char.class, char.class);
        methodHandle = lookup.findVirtual(String.class, "replace", methodType);
        str = (String) methodHandle.invokeExact("daddy", 'd', 'n');
        System.out.println(str);

        //Call it with loose arguments
        str = (String) methodHandle.invoke((Object) "daddy", 'd', 'n');
        System.out.println(str);

        //Looser not sure the dif between this and the last call.
        // weakly typed invocation (using MHs.invoke)
        str = (String) methodHandle.invokeWithArguments("sappy", 'p', 'v');
        System.out.println(str);


        //Call a static method, in this case java.util.Arrays.
        // mt is (Object[])List
        methodType = MethodType.methodType(java.util.List.class, Object[].class);
        methodHandle = lookup.findStatic(java.util.Arrays.class, "asList", methodType);
        List list = (List) methodHandle.invoke("one", "two");
        System.out.println(list);

        //If you don't really care about types, I think this would cause more boxing.
        //// mt is (Object,Object,Object)Object
        methodType = MethodType.genericMethodType(3);
        methodHandle = methodHandle.asType(methodType);
        obj = methodHandle.invokeExact((Object) 1, (Object) 2, (Object) 3);
        System.out.println(obj.getClass().getName());
        System.out.println(obj);


        //If you want to avoid auto-boxing you can cast to an int.
        //This is a Java 7 lang feature and it boggles my mind.
        //// mt is ()int
        methodType = MethodType.methodType(int.class);
        methodHandle = lookup.findVirtual(java.util.List.class, "size", methodType);
        int size = (int) methodHandle.invokeExact(java.util.Arrays.asList(1, 2, 3));
        System.out.println(size);


        //Look up a virtual method println on System.out
        methodType = MethodType.methodType(void.class, String.class);
        methodHandle = lookup.findVirtual(java.io.PrintStream.class, "println", methodType);
        methodHandle.invokeExact(System.out, "Hello, world.");


        //Lookup the getName method on Employee object
        methodType = MethodType.methodType(String.class);
        methodHandle = lookup.findVirtual(Employee.class, "getName", methodType);
        String name = (String) methodHandle.invokeExact(new Employee());
        System.out.println(name);


        //Get the declared for name, make is accessible then look up its callsite.
        Field fieldName = null;
        for (Field field : Employee.class.getDeclaredFields()) {
            if (field.getName().equals("name")) {
                fieldName = field;
                fieldName.setAccessible(true);
                break;
            }
        }
        methodHandle = lookup.unreflectGetter(fieldName);
        name = (String) methodHandle.invokeExact(new Employee());
        System.out.println(name);

        //
    }
}



Benchmarks

There is a performance improvement over reflection but it is complicated. It depends on how many times you make the calls. You probably only care if the code is in a tight loop.
The benchmarks that I have seen recently show 15x improvement over plain reflection, and only 2.5x slower than invoking a method in the normal way. But you know the old saying, believe nothing you hear and only 1/2 of what you read.
I figure I would try it out.
I have been fooling around with reflection and invokedynamic for a bit now. see A short write up on invoke dynamic.
Here are the results that I get using JDK 1.8 build 94.
One million calls (results are in nano seconds):
10,000 thousand calls
regular method call time        = 103
invoke dynamic method call time = 116
reflection method call time     = 252
100,000 thousand calls (after warmup).
regular method call time        = 46
invoke dynamic method call time = 112
reflection method call time     = 171
1,000,000 calls
regular method call time        = 23
invoke dynamic method call time = 35
reflection method call time     = 30
Reflection is faster at 1M than invoke dynamic. Ummm... Odd.
10,000,000 calls
regular method call time        = 34
invoke dynamic method call time = 24
reflection method call time     = 43
Now invoke dynamic is faster than a regular method call!
Now 100,000,000
regular method call time        = 22
invoke dynamic method call time = 24
reflection method call time     = 28
At this point, the JIT compiler takes all of the pain away. If you can't spare an extra 2 to 6 nano seconds, then you need to have some coping skills.
Here is the code to recreate the tests (also follow the above link):
    MethodHandles.Lookup lookup = MethodHandles.lookup();
    Class thisClass = lookup.lookupClass();  // (who am I?)

    MethodType methodType;
    MethodHandle methodHandle;
Create an employee object.
    Employee employee = new Employee();
Look up getName with invoke dynamic (see blog for a lot more examples, link above).
    //Lookup invoke dynamic
    methodType = MethodType.methodType(String.class);
    methodHandle = lookup.findVirtual(Employee.class, "getName", methodType);
    name = (String) methodHandle.invokeExact(new Employee());
    System.out.println("invoke dynamic " + name);
Look up Employee.getName with reflection.
    //Lookup reflection
    Method method = Employee.class.getMethod("getName", new Class<?>[]{});
    name = (String) method.invoke(new Employee());
    System.out.println("reflection " + name);
Start time, end time, number of iterations (times), calculated times, the usual suspects.
    long start = 0;
    long end = 0;
    long times = 100_000_000;
    long regularTime;
    long invokeDynamicTime;
    long reflectionTime;
    long count=0;
Now let's warm up the JVM.
    //warm up
    for (int index =0 ; index < times; index++) {
        employee.getName();
        name = (String) methodHandle.invokeExact(employee);
        name = (String) method.invoke(employee);
    }
Let's calculate regular method invocation.
    start = System.nanoTime();
    for (int index =0 ; index < times; index++) {
        name = employee.getName();
        count += name.hashCode();
    }
    count=0;
    end = System.nanoTime();
    regularTime = end - start;
    System.out.printf("regular method call time        = %d\n", regularTime/times);
P.S. I added the count, so my code would not get jitted away somehow.
Now let's calculate invokeDyanmic time.
    start = System.nanoTime();
    for (int index =0 ; index < times; index++) {
        name = (String) methodHandle.invokeExact(employee);
        count += name.hashCode();
    }
    count=0;
    end = System.nanoTime();
    invokeDynamicTime = end - start;

    System.out.printf("invoke dynamic method call time = %d\n", invokeDynamicTime/times);
Now let's calculate reflection time.
    start = System.nanoTime();
    for (int index =0 ; index < times; index++) {
        name = (String) method.invoke(employee);
        count += name.hashCode();
    }
    count=0;
    end = System.nanoTime();
    reflectionTime = end - start;
    System.out.printf("reflection method call time     = %d\n", reflectionTime/times);
I decided to add one more to the mix. If you really just want the property, then what if you just access the field directly.
10,000
regular method call time                  = 109
invoke dynamic method call time           = 115
reflection method call time               = 236
field method invoke dynamic call time     = 178
field method reflection call time         = 709
100_000
regular method call time                  = 49
invoke dynamic method call time           = 118
reflection method call time               = 312
field method invoke dynamic call time     = 75
field method reflection call time         = 158
1_000_000
regular method call time                  = 28
invoke dynamic method call time           = 41
reflection method call time               = 30
field method invoke dynamic call time     = 11
field method reflection call time         = 18
10_000_000
regular method call time                  = 28
invoke dynamic method call time           = 41
reflection method call time               = 30
field method invoke dynamic call time     = 11
field method reflection call time         = 18
100_000_000
regular method call time                  = 40
invoke dynamic method call time           = 25
reflection method call time               = 44
field method invoke dynamic call time     = 10
field method reflection call time         = 9
Ok, here is the code for the field access which is 4x faster than using employee.getName().
    long start = 0;
    long end = 0;
    long times = 10_000_000;
    long regularTime;
    long invokeDynamicTime;
    long reflectionTime;
    long invokeDynamicTimeUsingField;
    long fieldDirect;

    long count=0;

    //warm up
    for (int index =0 ; index < times; index++) {
        employee.getName();
        name = (String) methodHandle.invokeExact(employee);
        name = (String) method.invoke(employee);
        name = (String) methodHandleFieldDirect.invokeExact(employee);
    }


    start = System.nanoTime();
    for (int index =0 ; index < times; index++) {
        name = employee.getName();
        count += name.hashCode();
    }
    count=0;
    end = System.nanoTime();
    regularTime = end - start;
    System.out.printf("    regular method call time                  = %d\n", regularTime/times);

    start = System.nanoTime();
    for (int index =0 ; index < times; index++) {
        name = (String) methodHandle.invokeExact(employee);
        count += name.hashCode();
    }
    count=0;
    end = System.nanoTime();
    invokeDynamicTime = end - start;

    System.out.printf("    invoke dynamic method call time           = %d\n", invokeDynamicTime/times);

    start = System.nanoTime();
    for (int index =0 ; index < times; index++) {
        name = (String) method.invoke(employee);
        count += name.hashCode();
    }
    count=0;
    end = System.nanoTime();
    reflectionTime = end - start;
    System.out.printf("    reflection method call time               = %d\n", reflectionTime/times);


    start = System.nanoTime();
    for (int index =0 ; index < times; index++) {
        name = (String) methodHandleFieldDirect.invokeExact(employee);
        count += name.hashCode();
    }
    count=0;
    end = System.nanoTime();
    invokeDynamicTimeUsingField = end - start;
    System.out.printf("    field method invoke dynamic call time     = %d\n", invokeDynamicTimeUsingField/times);

    //
    start = System.nanoTime();
    for (int index =0 ; index < times; index++) {
        name = (String) fieldName.get(employee);
        count += name.hashCode();
    }
    count=0;
    end = System.nanoTime();
    fieldDirect = end - start;
    System.out.printf("    field method reflection call time         = %d\n", fieldDirect/times);

}
Now the actual field reflection / invoke dynamic code:
    Employee employee = new Employee();

    fieldName = null;
    for (Field field : Employee.class.getDeclaredFields()) {
        if (field.getName().equals("name")) {
            fieldName = field;
            fieldName.setAccessible(true);
            break;
        }
    }
    MethodHandle methodHandleFieldDirect = lookup.unreflectGetter(fieldName);
    name = (String) methodHandleFieldDirect.invokeExact(new Employee());
    System.out.println("method handle for field direct " + name);

    //Lookup invoke dynamic
    methodType = MethodType.methodType(String.class);
    methodHandle = lookup.findVirtual(Employee.class, "getName", methodType);
    name = (String) methodHandle.invokeExact(new Employee());
    System.out.println("invoke dynamic " + name);

    //Lookup reflection
    Method method = Employee.class.getMethod("getName", new Class<?>[]{});
    name = (String) method.invoke(new Employee()); 
    System.out.println("reflection " + name);

2 comments:

  1. Hey Rick,

    You never read the String name variable inside of the main method, are you sure it does not get removed from JIT while executing it?

    Chris

    ReplyDelete
  2. I think I tried it both ways, and it did not seem to make a dif.

    ReplyDelete

Kafka and Cassandra support, training for AWS EC2 Cassandra 3.0 Training