Janino 3.1.2 is 10x slower than 3.0.11

[chaokunyang]

Compared to janino 3.0.11, janino 3.1.2 is ten times slower. Is this expected?

Reproduce

Test case

  // For 3.0.11: Total cost 98.523273 ms, average time is 1.970465 ms
  // For 3.1.2: Total cost 15863.328650 ms, average time is 317.266573 ms
  @Test
  public void benchmark() throws Exception {
    CompileUnit unit = new CompileUnit("demo.pkg1", "A", (""
        + "package demo.pkg1;\n"
        + "public class A {\n"
        + "  public static String hello() { return \"HELLO\"; }\n"
        + "}"
    ));
    // Since janino is not called frequently, we test only 50 times.
    int iterNums = 50;
    for (int i = 0; i < iterNums; i++) {
      JaninoUtils.compile(Thread.currentThread().getContextClassLoader(), unit);
    }
    long startTime = System.nanoTime();
    for (int i = 0; i < iterNums; i++) {
      JaninoUtils.compile(Thread.currentThread().getContextClassLoader(), unit);
    }
    long duration = System.nanoTime() - startTime;
    System.out.printf("Total cost %f ms, average time is %f ms",
        (double) duration / 1000_000,
        (double) duration / iterNums / 1000_000);
  }

3.1.2

package io.ray.fury.codegen;

import java.io.IOException;
import java.nio.file.Files;
import java.nio.file.Path;
import java.nio.file.Paths;
import java.util.ArrayList;
import java.util.HashMap;
import java.util.List;
import java.util.Map;
import org.codehaus.commons.compiler.CompileException;
import org.codehaus.commons.compiler.util.reflect.ByteArrayClassLoader;
import org.codehaus.commons.compiler.util.resource.MapResourceCreator;
import org.codehaus.commons.compiler.util.resource.MapResourceFinder;
import org.codehaus.commons.compiler.util.resource.Resource;
import org.codehaus.janino.ClassLoaderIClassLoader;
import org.codehaus.janino.Compiler;

/**
 * A util to compile code to bytecode and create classloader to load generated class.
 * Based on org.codehaus.janino.tests.CompilerTest#testInMemoryCompilation,
 * see (https://github.com/janino-compiler/janino/issues/52)
 */
public class JaninoUtils {

  public static ClassLoader compile(ClassLoader parentClassLoader, CompileUnit... compileUnits) {
    final Map<String, byte[]> classes = toBytecode(parentClassLoader, compileUnits);
    // Set up a class loader that finds and defined the generated classes.
    return new ByteArrayClassLoader(classes, parentClassLoader);
  }

  public static List<byte[]> compileToBytecode(ClassLoader parentClassLoader, CompileUnit... compileUnits) {
    final Map<String, byte[]> classes = toBytecode(parentClassLoader, compileUnits);
    List<byte[]> byteCodes = new ArrayList<>(compileUnits.length);
    for (CompileUnit unit : compileUnits) {
      String key = unit.pkg.replace(".", "/") + "/" + unit.mainClassName + ".class";
      byteCodes.add(classes.get(key));
    }
    return byteCodes;
  }

  private static Map<String, byte[]> toBytecode(ClassLoader parentClassLoader, CompileUnit... compileUnits) {
    MapResourceFinder sourceFinder = new MapResourceFinder();
    for (CompileUnit unit : compileUnits) {
      String stubFileName = unit.pkg.replace(".", "/") + "/" + unit.mainClassName + ".java";
      sourceFinder.addResource(stubFileName, unit.getCode());

      Path path = Paths.get(CodeGenerator.getCodeDir(), stubFileName).toAbsolutePath();
      try {
        path.getParent().toFile().mkdirs();
        if (CodeGenerator.deleteCodeOnExit()) {
          path.toFile().deleteOnExit();
        }
        Files.write(path, unit.getCode().getBytes());
      } catch (IOException e) {
        throw new RuntimeException(String.format("Write code file %s failed", path), e);
      }
    }

    // Storage for generated bytecode
    final Map<String, byte[]> classes = new HashMap<>();
    // Set up the compiler.
    ClassLoaderIClassLoader iClassLoader = new ClassLoaderIClassLoader(parentClassLoader);
    Compiler compiler = new Compiler();
    compiler.setSourceFinder(sourceFinder);
    compiler.setIClassLoader(iClassLoader);
    compiler.setClassFileCreator(new MapResourceCreator(classes));
    compiler.setClassFileFinder(new MapResourceFinder(classes));

    // set debug flag to get source file names and line numbers for debug and stacktrace.
    // this is also the default behaviour for javac.
    compiler.setDebugSource(true);
    compiler.setDebugLines(true);

    // Compile all sources
    try {
      compiler.compile(sourceFinder.resources().toArray(new Resource[0]));
    } catch (CompileException | IOException e) {
      StringBuilder msgBuilder = new StringBuilder("Compile error: \n");
      for (int i = 0; i < compileUnits.length; i++) {
        CompileUnit unit = compileUnits[i];
        if (i != 0) {
          msgBuilder.append('\n');
        }
        String qualifiedName = unit.pkg + "." + unit.mainClassName;
        msgBuilder.append(qualifiedName).append(":\n");
        msgBuilder.append(CodeFormatter.format(unit.getCode()));
      }
      throw new CodegenException(msgBuilder.toString(), e);
    }

    return classes;
  }

}

3.0.11

package io.ray.fury.codegen;

import java.io.IOException;
import java.nio.file.Files;
import java.nio.file.Path;
import java.nio.file.Paths;
import java.util.ArrayList;
import java.util.HashMap;
import java.util.List;
import java.util.Map;
import org.codehaus.commons.compiler.CompileException;
import org.codehaus.janino.ByteArrayClassLoader;
import org.codehaus.janino.ClassLoaderIClassLoader;
import org.codehaus.janino.Compiler;
import org.codehaus.janino.util.resource.MapResourceCreator;
import org.codehaus.janino.util.resource.MapResourceFinder;
import org.codehaus.janino.util.resource.Resource;

/**
 * A util to compile code to bytecode and create classloader to load generated class.
 * Based on org.codehaus.janino.tests.CompilerTest#testInMemoryCompilation,
 * see (https://github.com/janino-compiler/janino/issues/52)
 */
public class JaninoUtils {

  public static ClassLoader compile(ClassLoader parentClassLoader, CompileUnit... compileUnits) {
    final Map<String, byte[]> classes = toBytecode(parentClassLoader, compileUnits);
    // Set up a class loader that finds and defined the generated classes.
    return new ByteArrayClassLoader(classes, parentClassLoader);
  }

  public static List<byte[]> compileToBytecode(ClassLoader parentClassLoader, CompileUnit... compileUnits) {
    final Map<String, byte[]> classes = toBytecode(parentClassLoader, compileUnits);
    List<byte[]> byteCodes = new ArrayList<>(compileUnits.length);
    for (CompileUnit unit : compileUnits) {
      String key = unit.pkg.replace(".", "/") + "/" + unit.mainClassName + ".class";
      byteCodes.add(classes.get(key));
    }
    return byteCodes;
  }

  private static Map<String, byte[]> toBytecode(ClassLoader parentClassLoader, CompileUnit... compileUnits) {
    MapResourceFinder sourceFinder = new MapResourceFinder();
    for (CompileUnit unit : compileUnits) {
      String stubFileName = unit.pkg.replace(".", "/") + "/" + unit.mainClassName + ".java";
      sourceFinder.addResource(stubFileName, unit.getCode());

      Path path = Paths.get(CodeGenerator.getCodeDir(), stubFileName).toAbsolutePath();
      try {
        path.getParent().toFile().mkdirs();
        if (CodeGenerator.deleteCodeOnExit()) {
          path.toFile().deleteOnExit();
        }
        Files.write(path, unit.getCode().getBytes());
      } catch (IOException e) {
        throw new RuntimeException(String.format("Write code file %s failed", path), e);
      }
    }

    // Storage for generated bytecode
    final Map<String, byte[]> classes = new HashMap<>();
    // Set up the compiler.
    ClassLoaderIClassLoader iClassLoader = new ClassLoaderIClassLoader(parentClassLoader);
    Compiler compiler = new Compiler(sourceFinder, iClassLoader);
    compiler.setClassFileCreator(new MapResourceCreator(classes));
    compiler.setClassFileFinder(new MapResourceFinder(classes));

    // set debug flag to get source file names and line numbers for debug and stacktrace.
    // this is also the default behaviour for javac.
    compiler.setDebugSource(true);
    compiler.setDebugLines(true);

    // Compile all sources
    try {
      compiler.compile(sourceFinder.resources().toArray(new Resource[0]));
    } catch (CompileException | IOException e) {
      StringBuilder msgBuilder = new StringBuilder("Compile error: \n");
      for (int i = 0; i < compileUnits.length; i++) {
        CompileUnit unit = compileUnits[i];
        if (i != 0) {
          msgBuilder.append('\n');
        }
        String qualifiedName = unit.pkg + "." + unit.mainClassName;
        msgBuilder.append(qualifiedName).append(":\n");
        msgBuilder.append(CodeFormatter.format(unit.getCode()));
      }
      throw new CodegenException(msgBuilder.toString(), e);
    }

    return classes;
  }

}

Result

In my macos machine:

For 3.0.11: Total cost 98.523273 ms, average time is 1.970465 ms
For 3.1.2: Total cost 15863.328650 ms, average time is 317.266573 ms

[aunkrig]

Reproduced. Obviously the preformance problem came with version 3.0.13:

Version avg time
3.1.2   29.2
3.1.0   31.9
3.0.15  41.0
3.0.13  37.6  <====
3.0.12   4.3
3.0.11   3.9

With janino 3.1.2:
Total cost 1853,276200 ms, average time is 37,065524 ms
Total cost 1841,929300 ms, average time is 36,838586 ms
Total cost 1461,608400 ms, average time is 29,232168 ms

With janino 3.1.0:
Total cost 1891,051700 ms, average time is 37,821034 ms
Total cost 1593,990100 ms, average time is 31,879802 ms
Total cost 2408,002500 ms, average time is 48,160050 ms

With janino 3.0.15:
Total cost 2148,505900 ms, average time is 42,970118 ms
Total cost 2049,264100 ms, average time is 40,985282 ms
Total cost 2056,877900 ms, average time is 41,137558 ms

With janino 3.0.13:
Total cost 1922,317800 ms, average time is 38,446356 ms
Total cost 1879,047900 ms, average time is 37,580958 ms
Total cost 1919,019700 ms, average time is 38,380394 ms

With janino 3.0.12:
Total cost 403,964100 ms, average time is 8,079282 ms
Total cost 213,540100 ms, average time is 4,270802 ms
Total cost 293,718600 ms, average time is 5,874372 ms

With janino 3.0.11:
Total cost 299,932400 ms, average time is 5,998648 ms
Total cost 418,975500 ms, average time is 8,379510 ms
Total cost 197,536300 ms, average time is 3,950726 ms
Total cost 208,709200 ms, average time is 4,174184 ms

Let's see...

[aunkrig]

Here's the root of the problem:

1694: Last 3.0.13-SNAPSHOT version: Total cost 2519,020800 ms, average time is 50,380416 ms
1680: Total cost 2335,045800 ms, average time is 46,700916 ms
1679: NPE
1678: Total cost 220,313700 ms, average time is 4,406274 ms
1623: First 3.0.13-SNAPSHOT version: Total cost 630,607500 ms, average time is 12,612150 ms

So the problem must lie in revision 1679 and/or 1680.

However that's a lot of changes, in particular revision 1680:

r1680 | arno.unkrig | 2019-05-17 16:33:26 MESZ
Changed paths:
M /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/util/StringUtil.java
M /trunk/janino/src/main/java/org/codehaus/janino/util/resource/MultiResourceFinder.java
D /trunk/commons-compiler-jdk/src/main/java/org/codehaus/commons/compiler/jdk/java9/java/lang/module
D /trunk/commons-compiler-jdk/src/main/java/org/codehaus/commons/compiler/jdk/java9/java/util
D /trunk/commons-compiler-jdk/src/main/java/org/codehaus/commons/compiler/jdk/java9/java/util/package-info.java
M /trunk/janino/src/main/java/org/codehaus/janino/Compiler.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/util/resource/DirectoryResourceFinder.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/util/resource/FileResourceFinder.java
M /trunk/janino/src/main/java/org/codehaus/janino/util/resource/JarDirectoriesResourceFinder.java
D /trunk/commons-compiler-jdk/src/main/java/org/codehaus/commons/compiler/jdk/java9/java/lang/module/ModuleFinder.java
M /trunk/janino/src/main/java/org/codehaus/janino/AbstractCompiler.java
D /trunk/commons-compiler-jdk/src/main/java/org/codehaus/commons/compiler/jdk/java9/java
M /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/ICompiler.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/java9/java/lang/module/ModuleReader.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/java9/java/lang/module/ModuleFinder.java
D /trunk/janino/src/main/java/org/codehaus/janino/util/resource/FileResourceFinder.java
D /trunk/janino/src/main/java/org/codehaus/janino/util/resource/Resource.java
D /trunk/commons-compiler-jdk/src/main/java/org/codehaus/commons/compiler/jdk/java9/java/util/Stream.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/java9/java/util/function/Consumer.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/util/resource/Resource.java
D /trunk/janino/src/main/java/org/codehaus/janino/util/resource/ResourceFinder.java
D /trunk/commons-compiler-jdk/src/main/java/org/codehaus/commons/compiler/jdk/java9/java/util/function/Consumer.java
M /trunk/janino/src/main/java/org/codehaus/janino/CachingJavaSourceClassLoader.java
D /trunk/janino/src/main/java/org/codehaus/janino/util/resource/DirectoryResourceFinder.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/java9/java/lang/module
M /trunk/janino/src/main/java/org/codehaus/janino/util/ResourceFinderClassLoader.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/util/resource
M /trunk/janino/src/main/java/org/codehaus/janino/JavaSourceIClassLoader.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/java9/java/lang
M /trunk/janino/src/main/java/org/codehaus/janino/ResourceFinderIClassLoader.java
M /trunk/janino/src/main/java/org/codehaus/janino/util/resource/MapResourceCreator.java
D /trunk/janino/src/main/java/org/codehaus/janino/util/resource/ResourceCreator.java
M /trunk/janino/src/main/java/org/codehaus/janino/util/ClassFile.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/java9/java/util/function
D /trunk/janino/src/main/java/org/codehaus/janino/util/resource/FileResourceCreator.java
D /trunk/commons-compiler-jdk/src/main/java/org/codehaus/commons/compiler/jdk/java9/java/lang/module/package-info.java
M /trunk/janino/src/main/java/org/codehaus/janino/util/resource/PathResourceFinder.java
D /trunk/janino/src/main/java/org/codehaus/janino/util/resource/FileResource.java
D /trunk/commons-compiler-jdk/src/main/java/org/codehaus/commons/compiler/jdk/java9/java/util/function
D /trunk/commons-compiler-jdk/src/main/java/org/codehaus/commons/compiler/jdk/java9/java/lang
M /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/samples/CompilerDemo.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/util/resource/DirectoryResourceCreator.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/util/resource/FileResource.java
D /trunk/commons-compiler-jdk/src/main/java/org/codehaus/commons/compiler/jdk/java9/java/util/function/package-info.java
D /trunk/commons-compiler-jdk/src/main/java/org/codehaus/commons/compiler/jdk/java9/java/lang/module/ModuleReader.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/util/resource/FileResourceCreator.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/java9/java/util/Stream.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/java9/java/util/Optional.java
D /trunk/commons-compiler-jdk/src/main/java/org/codehaus/commons/compiler/jdk/java9/java/util/Optional.java
M /trunk/janino/src/main/java/org/codehaus/janino/util/resource/StringResource.java
M /trunk/janino/src/main/java/org/codehaus/janino/util/resource/MapResourceFinder.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/util/resource/package-info.java
M /trunk/commons-compiler-jdk/src/main/java/org/codehaus/commons/compiler/jdk/JavaSourceClassLoader.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/java9/java/lang/module/package-info.java
M /trunk/janino/src/main/java/org/codehaus/janino/IClassLoader.java
D /trunk/janino/src/main/java/org/codehaus/janino/util/resource/DirectoryResourceCreator.java
M /trunk/janino/src/main/java/org/codehaus/janino/util/resource/package-info.java
D /trunk/commons-compiler-jdk/src/main/java/org/codehaus/commons/compiler/jdk/java9
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/java9/java/lang/module/ModuleReference.java
M /trunk/janino/src/main/java/org/codehaus/janino/util/resource/LazyMultiResourceFinder.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/util/resource/ResourceCreator.java
M /trunk/janino/src/test/java/org/codehaus/janino/tests/CompilerTest.java
M /trunk/commons-compiler-jdk/src/main/java/org/codehaus/commons/compiler/jdk/ClassLoaders.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/java9
M /trunk/janino/src/main/java/org/codehaus/janino/JavaSourceClassLoader.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/java9/java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/util/resource/ResourceFinder.java
M /trunk/janino/src/main/java/org/codehaus/janino/util/resource/ZipFileResourceFinder.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/java9/java/util
D /trunk/commons-compiler-jdk/src/main/java/org/codehaus/commons/compiler/jdk/java9/java/lang/module/ModuleReference.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/java9/java/util/function/package-info.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/java9/java/util/package-info.java

Now the "org.codehaus.janino.Compiler" is ALMOST working under JVM 9+.

r1679 | arno.unkrig | 2019-05-17 11:13:33 MESZ
Changed paths:
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/util/StringUtil.java
M /trunk/janino/src/main/java/org/codehaus/janino/AntCompilerAdapter.java
M /trunk/janino/.settings/org.eclipse.jdt.ui.prefs
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/samples/CompilerDemo.java
M /trunk/janino/src/main/java/org/codehaus/janino/Compiler.java
M /trunk/janino/src/main/java/org/codehaus/janino/IClassLoader.java
A /trunk/janino/src/main/java/org/codehaus/janino/AbstractCompiler.java
M /trunk/janino/src/main/java/org/codehaus/janino/CompilerFactory.java
M /trunk/janino/src/main/java/org/codehaus/janino/UnitCompiler.java
M /trunk/janino/src/main/java/org/codehaus/janino/util/resource/PathResourceFinder.java
M /trunk/janino/launch/janino-tests (JavaSE-11).launch
M /trunk/janino/launch/janino-tests (jdk-11-ea+26).launch
M /trunk/commons-compiler-jdk/src/main/java/org/codehaus/commons/compiler/jdk/CompilerFactory.java
M /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/ICompilerFactory.java
A /trunk/commons-compiler/src/main/java/org/codehaus/commons/compiler/ICompiler.java

#88: Support for JDK 9/10 in Full Compiler

[aunkrig]

The good news is: Only the "full compiler" is affected, not ExpressionEvaluator, ScriptEvaluator, ClassBodyEvaluator and SimpleCompiler.

Actually, these changes should only be an API improvement (extracting an ICompiler interface and an AbstractCompiler class from the org.codehaus.janino.Compiler class). Something must have gone wrong here...

I will check soon.

But at least it's "only" the full compiler, puh.

[chaokunyang]

Thanks for looking into this. I'm using the full compiler. The 3.0.11 works fine for me.

[aunkrig]

And here's the solution to the riddle:

3.0.13 implements

Issue #88: Support for JDK 9/10 in Full Compiler

The mechanism to find classes on the BOOTCLASSPATH has totally changed from JDK 8 to JDK 9: Previously, the classes were in in a .jar file (typically "jre/lib/rt.jar"), but JDK 9 has them in a super-magic class store that must be accessed through URLs like jrt:/java.base/java/io/ObjectOutputStream.class, which is obviously much slower

I remember that 3.0.12 didn't work at all with JRE 9. It is strange that the JANINO 3.0.12 (and 3.0.11) full compiler now seem to work well with JRE 9+, but I believe that is only by accident. Please be prepared to problems if you use 3.0.11 with JDK 9+!

[aunkrig]

Fixed issue #131: Janino 3.1.2 is 10x slower than 3.0.11:
The Compiler's IClassLoader was initialized way too eagerly, thus lots of classes were loaded from the class path, which is very slow.

Now the full compiler is fast again; please test the HEAD version and confirm that the fix is OK.

[aunkrig]

Total cost 229,805100 ms, average time is 4,596102 ms
Total cost 253,251000 ms, average time is 5,065020 ms
Total cost 335,494600 ms, average time is 6,709892 ms

(Same as for JANINO 3.0.11.)

[aunkrig]

Thank you for reporting this really bad bug!

[chaokunyang]

Awsome, thanks for the fix.

[aunkrig]

You're welcome. Do you want/need an official JANINO version?

[chaokunyang]

An official JANINO version would be great.

[igreenfield]

I also need official version

[aunkrig]

By popular request, Janino 3.1.3 is now out the door, including the fix for this issue. Have fun!