java runtime UnsatisfiedLinkError when loading jni dll from jar

[Zhuoqing]

Describe the bug
looks like the onnx java runtime will try to save the runtime dll into tempfile (C:\Users\zhwu\AppData\Local\Temp\onnxruntime4620205959932865852.dll) and then call System.load for that temp file. And same for the jni dll.
However in my local box seems when loading the jni dll (onnxruntime4j_jni2846808251558359431.dll) I got UnsatisfiedLinkError. Seems it is expecting onnxruntime.dll, not the temp file onnxruntime4620205959932865852.dll. If I manually put onnxruntime.dll in PATH the problem goes away.

Urgency
none.

System information

• OS Platform and Distribution (Windows 10):
• ONNX Runtime installed from (source):
• ONNX Runtime version: 1.11
• Python version:
• Visual Studio version (if applicable):
• GCC/Compiler version (if compiling from source):
• CUDA/cuDNN version:
• GPU model and memory:

To Reproduce
Describe steps/code to reproduce the behavior:
Reference built onnxruntime4j-1.1.0-with-binaries.jar and run sample java program.

Expected behavior
A clear and concise description of what you expected to happen.
sample java program can finish successfully.

Screenshots

Jan 22, 2020 1:22:19 PM ai.onnxruntime.OnnxRuntime init
INFO: Loading from classpath resource
Jan 22, 2020 1:22:19 PM ai.onnxruntime.OnnxRuntime init
INFO: Attempting to load library from classpath using /onnxruntime.dll
Jan 22, 2020 1:22:19 PM ai.onnxruntime.OnnxRuntime createTempFileFromResource
INFO: Writing /onnxruntime.dll out to C:\Users\zhwu\AppData\Local\Temp\onnxruntime4116550111504310707.dll
Jan 22, 2020 1:22:19 PM ai.onnxruntime.OnnxRuntime init
INFO: Failed load resource File /onnxruntime.dll was not found inside JAR.
Jan 22, 2020 1:22:19 PM ai.onnxruntime.OnnxRuntime init
INFO: Failed to load from testing location, looking for /lib/
Jan 22, 2020 1:22:19 PM ai.onnxruntime.OnnxRuntime init
INFO: Attempting to load library from classpath using /lib/onnxruntime.dll
Jan 22, 2020 1:22:19 PM ai.onnxruntime.OnnxRuntime createTempFileFromResource
INFO: Writing /lib/onnxruntime.dll out to C:\Users\zhwu\AppData\Local\Temp\onnxruntime4620205959932865852.dll
Jan 22, 2020 1:22:19 PM ai.onnxruntime.OnnxRuntime init
INFO: Copied resource /lib/onnxruntime.dll to location C:\Users\zhwu\AppData\Local\Temp\onnxruntime4620205959932865852.dll
Jan 22, 2020 1:22:19 PM ai.onnxruntime.OnnxRuntime init
INFO: Attempting to load library from classpath using /onnxruntime4j_jni.dll
Jan 22, 2020 1:22:19 PM ai.onnxruntime.OnnxRuntime createTempFileFromResource
INFO: Writing /onnxruntime4j_jni.dll out to C:\Users\zhwu\AppData\Local\Temp\onnxruntime4j_jni5135653575603213948.dll
Jan 22, 2020 1:22:19 PM ai.onnxruntime.OnnxRuntime init
INFO: Failed load resource File /onnxruntime4j_jni.dll was not found inside JAR.
Jan 22, 2020 1:22:19 PM ai.onnxruntime.OnnxRuntime init
INFO: Failed to load from testing location, looking for /lib/
Jan 22, 2020 1:22:19 PM ai.onnxruntime.OnnxRuntime init
INFO: Attempting to load library from classpath using /lib/onnxruntime4j_jni.dll
Jan 22, 2020 1:22:19 PM ai.onnxruntime.OnnxRuntime createTempFileFromResource
INFO: Writing /lib/onnxruntime4j_jni.dll out to C:\Users\zhwu\AppData\Local\Temp\onnxruntime4j_jni2846808251558359431.dll
Jan 22, 2020 1:22:19 PM ai.onnxruntime.OnnxRuntime init
INFO: Copied resource /lib/onnxruntime4j_jni.dll to location C:\Users\zhwu\AppData\Local\Temp\onnxruntime4j_jni2846808251558359431.dll

java.lang.UnsatisfiedLinkError: C:\Users\zhwu\AppData\Local\Temp\onnxruntime4j_jni2846808251558359431.dll: Can't find dependent libraries
at java.lang.ClassLoader$NativeLibrary.load(Native Method)
at java.lang.ClassLoader.loadLibrary0(ClassLoader.java:1934)
at java.lang.ClassLoader.loadLibrary(ClassLoader.java:1817)
at java.lang.Runtime.load0(Runtime.java:809)
at java.lang.System.load(System.java:1086)
at ai.onnxruntime.OnnxRuntime.init(OnnxRuntime.java:106)
at ai.onnxruntime.OrtEnvironment.(OrtEnvironment.java:55)

[faxu]

CC @Craigacp

[Craigacp]

That's very odd. The logging indicates that it found onnxruntime.dll and loaded it from the classpath, and then found onnxruntime4j_jni.dll and loaded that. Unfortunately the debug logging doesn't have a message that says it correctly loaded the library, but that's the only way for it to proceed. The second load failed with a Can't find dependent libraries error, which usually indicates that the onnxruntime was compiled with a provider that it can't find the dll for. The dll name being different for the extracted file didn't cause any issues in the Windows CI pipeline, so I'd be very surprised if it was the name changing.

What arguments did you provide to build.sh, and do you have multiple versions of Java on the system? Are there any other dlls in the folder with the onnxruntime.dll that you added to PATH?

[Zhuoqing]

Thanks @Craigacp . Any chance the windows CI pipeline machine somehow will build an onnxruntime.dll on PATH? I build rel-1.1.1 branch on windows using build.bat --config RelWithDebInfo --build_shared_lib --parallel --build_java and onnxruntime.dll is the only extra dll I manually added to PATH
The link command for onnxruntime4j_jni shows it is reading ONNXRUNTIME.LIB and does that cause a hard dependence on onnxruntime.dll? The depencewalker also shows dependence on onnxruntime.dll

link.command.1.tlog
link.read.1.tlog

[Craigacp]

I think the PATH was changed a bit for the Windows CI pipeline, @shahasad would know. I should be able to modify the loader so that it creates a temporary directory with a random name and then loads the libraries with unchanged names from that directory, which should fix it if it is indeed a naming issue. I'll try that and report back.

[yuzawa-san]

If you want to download my branch from the above PR: https://github.com/yuzawa-san/onnxruntime/tree/java-gradle and try that out. That was a minor refactor of the loader and it has more info messages.

[mina-asham]

EDIT: Even without the JNI dlls being built, it failed expecting onnxruntime.dll to be available on the path

This might be related to this pull request: #2873
I was getting a similar issue (although mine were clear about which dependent libraries were missing), your link log is showing:

C:\PROGRAM FILES\JAVA\JDK1.8.0_231\LIB\JAWT.LIB
C:\PROGRAM FILES\JAVA\JDK1.8.0_231\LIB\JVM.LIB

You can try adding them to your library path and see if it makes a change?

[Zhuoqing]

Tried temporary directory with a random name and then loads the libraries with unchanged names from that directory And it works for me on my Windows machine. https://github.com/Zhuoqing/onnxruntime/pull/1/files

[Craigacp]

Cool. I'm just in the middle of building my version of that patch. It makes a single directory for all the libraries and then passes that through the loading functions. The patch works on Linux, I'm just persuading my Windows VM to build it at the moment.

[Craigacp]

This fix Craigacp@3aef280 works on Windows and doesn't change any behaviour on Linux. Not had chance to check on macOS yet, but I suspect it'll be fine. We should try and incorporate the fix into #2866 which is rewriting the build system and also the native loader.

[saudet]

@Craigacp As discussed previously, please put up all the known limitations like these in a README file somewhere instead of leaving users in the dark and forcing them to post issues like this...

[Craigacp]

@saudet this was a bug, it's fixed by the build system rewrite that's awaiting merging.

[saudet]

From an end user's perspective, all the issues that I mentioned on pull #2215 (comment) are also "bugs".

However, I do not see you do anything about them and none of them have been fixed in the new pull request you mention. From what I understand, you consider all these issues as "limitations", which is fine, but they should be clearly stated in the documentation somewhere, because end users will run into them, and their opinions will differ from yours.

[Craigacp]

This should be fixed by the merging of #2866. @Zhuoqing could you check to see if the current master branch resolves your issue.

[faxu]

@Zhuoqing Is your issue addressed in the 1.2 release?

[stale]

This issue has been automatically marked as stale due to inactivity and will be closed in 7 days if no further activity occurs. If further support is needed, please provide an update and/or more details.

[stale]

This issue has been automatically closed due to inactivity. Please reactivate if further support is needed.