Magnitudes slower up_to.each loop on latest GraalVM

[JaroslavTulach]

As part of working on #6966 I tried to use the latest GraalVM. When running test/Tests I realized one test is taking ages. Turns out that:

import Standard.Base.Runtime.Ref.Ref
import Standard.Base.Data.Range
import Standard.Base.IO

main =
    cell = Ref.new 0
    n = 100000000
    0.up_to n . each a->
        if a % 100000 == 0 then IO.println a
        x = cell.get
        cell.put x+1
    IO.println cell.get

is running magnitudes slower than on currently used GraalVM. Probably RepeatingNode doesn't get inlined.

[JaroslavTulach]

The slowness is related to following warning:

enso$ ./built-distribution/enso-engine-0.0.0-dev-linux-amd64/enso-0.0.0-dev/bin/enso --run t.enso 
[engine] The internal option -Dtruffle.class.path.append option is deprecated. Languages must now always use the application module-path instead. To resolve this use the JVM option '--module-path ./built-distribution/enso-engine-0.0.0-dev-linux-amd64/enso-0.0.0-dev/bin/../component/runtime.jar' instead.
[To redirect Truffle log output to a file use one of the following options:
* '--log.file=<path>' if the option is passed using a guest language launcher.
* '-Dpolyglot.log.file=<path>' if the option is passed using the host Java launcher.
* Configure logging using the polyglot embedding API.]
[engine] WARNING: The polyglot engine uses a fallback runtime that does not support runtime compilation to native code.
Execution without runtime compilation will negatively impact the guest application performance.
The following cause was found: JVMCI is not enabled for this JVM. Enable JVMCI using -XX:+EnableJVMCI.
For more information see: https://www.graalvm.org/latest/reference-manual/embed-languages/.
To disable this warning use the '--engine.WarnInterpreterOnly=false' option or the '-Dpolyglot.engine.WarnInterpreterOnly=false' system property.

not sure why it doesn't pick the compiler up? My GraalVM has been built with:

graal/vm$ ~/bin/jdk-21/bin/java -version
openjdk version "21" 2023-09-19
OpenJDK Runtime Environment (build 21+35-jvmci-23.1-b15)
OpenJDK 64-Bit Server VM (build 21+35-jvmci-23.1-b15, mixed mode, sharing)
graal/vm$ mx --java-home ~/bin/jdk-21 --env ce-enso build
graal/vm$ cat mx.vm/ce-enso 
# mx --dy /espresso,/substratevm --components="Espresso libjvm,Java on Truffle,Truffle Macro,GraalVM license files" --disable-libpolyglot --non-rebuildable-images=lib:javavm --disable-installables=true graalvm-show --print-env
DYNAMIC_IMPORTS=/compiler,/graal-js,/espresso,/sdk,/substratevm,/truffle,/vm
COMPONENTS=ejvm,ejc,gvm,java,nfi,nfi-libffi,sdk,sdkc,sdkl,sdkni,tfl,tfla,tflc,tflm,js,jsl,jss,cmp
EXCLUDE_COMPONENTS=libpoly
NATIVE_IMAGES=lib:javavm,lib:jvmcicompiler
DISABLE_INSTALLABLES=True
NON_REBUILDABLE_IMAGES=lib:javavm

[chumer]

Yes the slowness is caused by the optimizing truffle runtime not being enabled.

Can you print the Java command line ´./built-distribution/enso-engine-0.0.0-dev-linux-amd64/enso-0.0.0-dev/bin/enso` is running underneath?

[JaroslavTulach]

At the end following Java command is executed:

enso$ java -jar \
  -Dtruffle.class.path.append=./built-distribution/enso-engine-0.0.0-dev-linux-amd64/enso-0.0.0-dev/bin/../component/runtime.jar \
  -Dgraal.PrintGraph=Network ./built-distribution/enso-engine-0.0.0-dev-linux-amd64/enso-0.0.0-dev/bin/../component/runner.jar \
  --run t.enso

[hubertp]

I don't think this is recent.

 INFO ide_ci::program::command: bashℹ️ Range:  [36/36, 2856ms]
...
 INFO ide_ci::program::command: bashℹ️     - should allow efficient iteration [2528ms]

has been notoriously slow for a really long time.

[chumer]

My next guess would be that you are not building with a labs JDK here:

graal/vm$ ~/bin/jdk-21/bin/java -version

My guess is that JVMCI is not enabled by default there.

Can you try: https://github.com/graalvm/labs-openjdk-21/releases/tag/jvmci-23.1-b15 instead?

GitHub

Release jvmci-23.1-b15 · graalvm/labs-openjdk-21

JDK 21 fork for building GraalVM CE. Contribute to graalvm/labs-openjdk-21 development by creating an account on GitHub.

[JaroslavTulach]

I went the easy path and built the GraalVM as:

graal/vm$ FASTR_RELEASE=true FASTR_NO_RECOMMENDED=true FASTR_CAPTURE_DEPENDENCIES=  mx --java-home ~/bin/labs-21 --env ce-complete build

then Enso works correctly, becomes subject to PE and runs fast.

[radeusgd]

I don't think this is recent.

 INFO ide_ci::program::command: bashℹ️ Range:  [36/36, 2856ms]
...
 INFO ide_ci::program::command: bashℹ️     - should allow efficient iteration [2528ms]

has been notoriously slow for a really long time.

btw. maybe we should try to set some kind of time limit on this test and fail it if it's too slow?

We've been doing something like that in a few places and it has worked relatively well - we sometimes get spurious failures, but they are rather rare.

enso/test/Table_Tests/src/In_Memory/Join_Performance_Spec.enso

Lines 10 to 32 in 42a8567

	Test.group "[In-Memory] Table.join performance" <|
	n = 10000
	Test.specify "should efficiently compute equality joins" <|
	vec = 0.up_to n . to_vector
	vec2 = 1.up_to n+1 . to_vector
	t1 = Table.new [["X", vec], ["Y", 0.up_to n . map (_ % 2)]]
	t2 = Table.new [["B", [0, 1]]]
	t3 = Table.new [["X", vec.reverse], ["Z", vec2]]
	r1 = Duration.time_execution <|
	t1.join t2 on=(Join_Condition.Equals "Y" "B")
	r2 = Duration.time_execution <|
	t1.join t3 on="X"
	t4 = r2.second . order_by ["X"]
	t4.at "X" . to_vector . should_equal <| vec
	t4.at "Z" . to_vector . should_equal <| vec2.reverse
	base_ms = r1.first.total_milliseconds
	expected_max_time_ms = base_ms * 5 + 100
	runtime_ms = r2.first.total_milliseconds
	if runtime_ms > expected_max_time_ms then
	Test.fail "Expected a join of "+n.to_text+"x"+n.to_text+" with linear result size to be efficient, but it took "+runtime_ms.to_text+"ms while a join of 2x"+n.to_text+" with the same result size took "+base_ms.to_text+"ms. The maximum time threshold for this operation to be deemed efficient has been estimated at "+expected_max_time_ms.to_text+"ms."

[JaroslavTulach]

Interesting comments by Christian on the future options of packaging Enso:

You use the GraalVM JDK and add your extensions on the module/class-path.
You could also consider shipping a JVM standalone like will start to do in the 23.1 release.
That standalone release could just drop all the jars for all the languages in a folder.
Jlinking a GraalVM JDK with the languages built in could be another way.
Basically ship it like you would ship a Java application.

For now we can stay with ce-complete config. It runs fast.

[JaroslavTulach]

I don't think this is recent.

 INFO ide_ci::program::command: bashℹ️ Range:  [36/36, 2856ms]
...
 INFO ide_ci::program::command: bashℹ️     - should allow efficient iteration [2528ms]

has been notoriously slow for a really long time.

I am not talking about 2s, but about minutes. Try:

enso$ JAVA_OPTS=-Dpolyglot.engine.Compilation=false ./built-distribution/enso-engine-0.0.0-dev-linux-amd64/enso-0.0.0-dev/bin/enso --run test/Tests/src/Data/Range_Spec.enso

btw. maybe we should try to set some kind of time limit on this test and fail it if it's too slow?

Or divide the number of iteration by hundred? Or remove the test altogether - we are supposed to have benchmarks for such operations (and I believe we do have them).

Sorry for the false panic, I was surprised the test doesn't finish and thought there is some endless loop there. Only the further investigation revealed it is just incorrectly built GraalVM without PE compiler.