Native invocation of libkruntime.so fails during java benchmark example

Question

Native invocation of libkruntime.so fails during java benchmark example

manuelleduc opened this issue 6 years ago · 5 comments

Hello,

I'm looking at krun in a virtualized environment, and everything works as expected until step 5 or the README.

Building the examples with make/make java-bench works perfectly, but during the benchmarks executions, I obtain a runtime error.

I'm running the benchmarks using the command below:

$ pwd
/home/.../krun/examples
$ ../krun.py java.krun --no-tickless-check
$ # also tried
$ LD_LIBRARY_PATH=$(pwd)/../libkrun/libkruntime.so ../krun.py java.krun --no-tickless-check

And the resulting log is:

[2019-07-03 14:54:12: WARNING] Virtualised system doesn't allow Krun to check the CPU governor.
[2019-07-03 14:54:12: WARNING] Virtualised system doesn't allow Krun to check the CPU scaler
[2019-07-03 14:54:12: WARNING] This appears to be a virtualised host. The results will be flawed. Use bare-metal for reliable results!
[2019-07-03 14:54:46: WARNING] platform does not support APERF and MPERF counts. Not checking ratios.
[2019-07-03 14:54:46: INFO] Finished 'nbody(15)' (default-c variant) under 'C'
[2019-07-03 14:54:46: INFO] Estimated completion (whole session): ????-??-?? ??:??:?? (?:??:?? from now)
[2019-07-03 14:54:46: INFO] 13 executions left in scheduler queue
[2019-07-03 14:54:46: INFO] Executions until ETA known: 5
[2019-07-03 14:54:46: INFO] Next execution is 'fannkuch_redux(100)' (default-c variant) under 'C'
[2019-07-03 14:54:46: INFO] Estimated completion (next execution): 2019-07-03 14:55:19 (0:00:32 from now)
[2019-07-03 14:54:46: INFO] Reboot in preparation for next execution
[2019-07-03 14:54:46: WARNING] SIMULATED: reboot (--hardware-reboots is OFF)
[2019-07-03 14:54:47: WARNING] Virtualised system doesn't allow Krun to check the CPU governor.
[2019-07-03 14:54:47: WARNING] Virtualised system doesn't allow Krun to check the CPU scaler
[2019-07-03 14:54:47: WARNING] This appears to be a virtualised host. The results will be flawed. Use bare-metal for reliable results!
[2019-07-03 14:55:20: WARNING] platform does not support APERF and MPERF counts. Not checking ratios.
[2019-07-03 14:55:20: INFO] Finished 'fannkuch_redux(100)' (default-c variant) under 'C'
[2019-07-03 14:55:20: INFO] Estimated completion (whole session): ????-??-?? ??:??:?? (?:??:?? from now)
[2019-07-03 14:55:20: INFO] 12 executions left in scheduler queue
[2019-07-03 14:55:20: INFO] Executions until ETA known: 4
[2019-07-03 14:55:20: INFO] Next execution is 'nbody(15)' (default-python variant) under 'PyPy'
[2019-07-03 14:55:20: INFO] Estimated completion (next execution): 2019-07-03 14:55:51 (0:00:31 from now)
[2019-07-03 14:55:20: INFO] Reboot in preparation for next execution
[2019-07-03 14:55:20: WARNING] SIMULATED: reboot (--hardware-reboots is OFF)
[2019-07-03 14:55:20: WARNING] Virtualised system doesn't allow Krun to check the CPU governor.
[2019-07-03 14:55:20: WARNING] Virtualised system doesn't allow Krun to check the CPU scaler
[2019-07-03 14:55:20: WARNING] This appears to be a virtualised host. The results will be flawed. Use bare-metal for reliable results!
[2019-07-03 14:56:04: WARNING] platform does not support APERF and MPERF counts. Not checking ratios.
[2019-07-03 14:56:04: INFO] Finished 'nbody(15)' (default-python variant) under 'PyPy'
[2019-07-03 14:56:04: INFO] Estimated completion (whole session): ????-??-?? ??:??:?? (?:??:?? from now)
[2019-07-03 14:56:04: INFO] 11 executions left in scheduler queue
[2019-07-03 14:56:04: INFO] Executions until ETA known: 3
[2019-07-03 14:56:04: INFO] Next execution is 'fannkuch_redux(100)' (default-python variant) under 'PyPy'
[2019-07-03 14:56:04: INFO] Estimated completion (next execution): 2019-07-03 14:56:47 (0:00:42 from now)
[2019-07-03 14:56:04: INFO] Reboot in preparation for next execution
[2019-07-03 14:56:04: WARNING] SIMULATED: reboot (--hardware-reboots is OFF)
[2019-07-03 14:56:05: WARNING] Virtualised system doesn't allow Krun to check the CPU governor.
[2019-07-03 14:56:05: WARNING] Virtualised system doesn't allow Krun to check the CPU scaler
[2019-07-03 14:56:05: WARNING] This appears to be a virtualised host. The results will be flawed. Use bare-metal for reliable results!
[2019-07-03 14:56:42: WARNING] platform does not support APERF and MPERF counts. Not checking ratios.
[2019-07-03 14:56:42: INFO] Finished 'fannkuch_redux(100)' (default-python variant) under 'PyPy'
[2019-07-03 14:56:42: INFO] Estimated completion (whole session): ????-??-?? ??:??:?? (?:??:?? from now)
[2019-07-03 14:56:42: INFO] 10 executions left in scheduler queue
[2019-07-03 14:56:42: INFO] Executions until ETA known: 2
[2019-07-03 14:56:42: INFO] Next execution is 'nbody(15)' (default-lua variant) under 'LuaJIT'
[2019-07-03 14:56:42: INFO] Estimated completion (next execution): 2019-07-03 14:57:18 (0:00:35 from now)
[2019-07-03 14:56:42: INFO] Reboot in preparation for next execution
[2019-07-03 14:56:42: WARNING] SIMULATED: reboot (--hardware-reboots is OFF)
[2019-07-03 14:56:43: WARNING] Virtualised system doesn't allow Krun to check the CPU governor.
[2019-07-03 14:56:43: WARNING] Virtualised system doesn't allow Krun to check the CPU scaler
[2019-07-03 14:56:43: WARNING] This appears to be a virtualised host. The results will be flawed. Use bare-metal for reliable results!
[2019-07-03 14:57:16: WARNING] platform does not support APERF and MPERF counts. Not checking ratios.
[2019-07-03 14:57:16: INFO] Finished 'nbody(15)' (default-lua variant) under 'LuaJIT'
[2019-07-03 14:57:16: INFO] Estimated completion (whole session): ????-??-?? ??:??:?? (?:??:?? from now)
[2019-07-03 14:57:16: INFO] 9 executions left in scheduler queue
[2019-07-03 14:57:16: INFO] Executions until ETA known: 1
[2019-07-03 14:57:16: INFO] Next execution is 'fannkuch_redux(100)' (default-lua variant) under 'LuaJIT'
[2019-07-03 14:57:16: INFO] Estimated completion (next execution): 2019-07-03 14:57:48 (0:00:31 from now)
[2019-07-03 14:57:16: INFO] Reboot in preparation for next execution
[2019-07-03 14:57:16: WARNING] SIMULATED: reboot (--hardware-reboots is OFF)
[2019-07-03 14:57:17: WARNING] Virtualised system doesn't allow Krun to check the CPU governor.
[2019-07-03 14:57:17: WARNING] Virtualised system doesn't allow Krun to check the CPU scaler
[2019-07-03 14:57:17: WARNING] This appears to be a virtualised host. The results will be flawed. Use bare-metal for reliable results!
[2019-07-03 14:57:50: WARNING] platform does not support APERF and MPERF counts. Not checking ratios.
[2019-07-03 14:57:50: INFO] Finished 'fannkuch_redux(100)' (default-lua variant) under 'LuaJIT'
[2019-07-03 14:57:50: INFO] Estimated completion (whole session): 2019-07-03 15:02:17 (0:04:27 from now)
[2019-07-03 14:57:50: INFO] 8 executions left in scheduler queue
[2019-07-03 14:57:50: INFO] Next execution is 'nbody(15)' (default-java variant) under 'Java'
[2019-07-03 14:57:50: INFO] Estimated completion (next execution): 2019-07-03 14:58:22 (0:00:31 from now)
[2019-07-03 14:57:50: INFO] Reboot in preparation for next execution
[2019-07-03 14:57:50: WARNING] SIMULATED: reboot (--hardware-reboots is OFF)
[2019-07-03 14:57:51: WARNING] Virtualised system doesn't allow Krun to check the CPU governor.
[2019-07-03 14:57:51: WARNING] Virtualised system doesn't allow Krun to check the CPU scaler
[2019-07-03 14:57:51: WARNING] This appears to be a virtualised host. The results will be flawed. Use bare-metal for reliable results!
[2019-07-03 14:58:22: INFO] stderr: Exception in thread "main" java.lang.UnsatisfiedLinkError: IterationsRunner.JNI_krun_init()V
[2019-07-03 14:58:22: INFO] stderr: 	at IterationsRunner.JNI_krun_init(Native Method)
[2019-07-03 14:58:22: INFO] stderr: 	at IterationsRunner.main(iterations_runner.java:248)
[2019-07-03 14:58:22: ERROR] Benchmark returned non-zero or emitted invalid JSON.
Exception string: No JSON object could be decoded
return code: 0
stdout:
--------------------------------------------------

--------------------------------------------------

stderr:
--------------------------------------------------
Exception in thread "main" java.lang.UnsatisfiedLinkError: IterationsRunner.JNI_krun_init()V
	at IterationsRunner.JNI_krun_init(Native Method)
	at IterationsRunner.main(iterations_runner.java:248)

--------------------------------------------------

[2019-07-03 14:58:22: INFO] Finished 'nbody(15)' (default-java variant) under 'Java'
[2019-07-03 14:58:23: INFO] Estimated completion (whole session): 2019-07-03 15:02:19 (0:03:56 from now)
[2019-07-03 14:58:23: INFO] 7 executions left in scheduler queue
[2019-07-03 14:58:23: INFO] Next execution is 'fannkuch_redux(100)' (default-java variant) under 'Java'
[2019-07-03 14:58:23: INFO] Estimated completion (next execution): 2019-07-03 14:58:53 (0:00:30 from now)
[2019-07-03 14:58:23: INFO] Reboot in preparation for next execution
[2019-07-03 14:58:23: WARNING] SIMULATED: reboot (--hardware-reboots is OFF)
[2019-07-03 14:58:23: WARNING] Virtualised system doesn't allow Krun to check the CPU governor.
[2019-07-03 14:58:23: WARNING] Virtualised system doesn't allow Krun to check the CPU scaler
[2019-07-03 14:58:23: WARNING] This appears to be a virtualised host. The results will be flawed. Use bare-metal for reliable results!
[...]

When I let the process go to its end, the java_results.json file does not seems to contains any time measurement results.

Am I missing an important step ?

Thanks.

PS: I'm really looking forward to test krun, and I really enjoyed reading
Virtual machine warmup blows hot and cold :)

Answer 1 · 2019-07-03T13:33:40.000Z

Hi manuelleduc,

I'm glad you enjoyed our paper, and thanks for trying Krun! :)

It looks like the JNI call is failing. Looking at the build system, I see that all of the JNI stubs in libkruntime are guarded by a preprocessor macro WITH_JAVA which is only turned on if the top-level Makefile passes down ENABLE_JAVA=1.

Can you try (in the top-level krun dir):

make clean
ENABLE_JAVA=1 make

And then try running the example again.

If this works, this is a bug in our documentation :)

Answer 2 · 2019-07-04T08:58:15.000Z

Thanks a lot.

Starting from a clean clone of krun, this build command did the job :

export ENABLE_JAVA=1
JAVA_HOME=/usr/lib/jvm/java-8-openjdk-amd64/ make JAVA_CPPFLAGS='"-I${JAVA_HOME}/include -I${JAVA_HOME}/include/linux"' JAVA_LDFLAGS=-L${JAVA_HOME}/lib ENABLE_JAVA=1

I'm guessing building krun first without options, then once with the java options activated lead to an unstable result.

This gist (https://gist.github.com/manuelleduc/cacb0aa2ee2abab94367f268a31a3e88) presents resulting java_results.json/data, which afaik, looks accurate.

Answer 3 · 2019-07-04T11:03:44.000Z

Great!

As far as I can see, this variable is not documented. Would you be up for raising a PR to document it?

Answer 4 · 2019-07-06T11:08:31.000Z

I'm happy to have a trouble-shooting section, but we should also mention earlier in the build steps that if you need java support, you need to set the environment variable.

What do you think?

Answer 5 · 2019-07-06T11:10:18.000Z

Near the following portion of README.md:

If you want to benchmark Java programs...