[SOLVED] Closure error on LibOVR

Started by Mickelukas, December 23, 2015, 23:06:21

Previous topic - Next topic

Mickelukas

Sometimes when starting up LibOVR with the latest build and exactly the same code as in the hello ovr example I get an error. It happens specifically if I just shut down the ovr and am starting it up again.
[LWJGL] ClosureError for closure: org.lwjgl.ovr.OVRLogCallback
[LWJGL] Enable debug mode to discover where the closure was instantiated.
[LWJGL] Exception in closure that was invoked asynchronously from a native thread.
org.lwjgl.system.libffi.ClosureError: Callback failed because the closure instance has been garbage collected.


Is there any way to check for the error before it happens and handle it correctly or is there another trick to work around it?

Also, I love the new wrapper! It's a lot easier to translate the Java code from the examples on the official LibOVR pages and I now understand the code a lot better :)

spasi

LWJGL callback instances must be strongly referenced as long as native code may invoke them. The current implementation uses a libffi closure and a weak reference to the callback instance. If the instance has been garbage collected when the closure is invoked, dereferencing the weak reference will return null and you get the above error message. This protects the JVM from crashing and you can use -Dorg.lwjgl.util.Debug=true to see where the callback was instantiated.

It's interesting that it happens with the HelloLibOVR sample though. I cannot reproduce it and it shouldn't happen afaict. What JVM are you using? (running LWJGL in debug mode prints all the relevant information)

Quote from: Mickelukas on December 23, 2015, 23:06:21It happens specifically if I just shut down the ovr and am starting it up again.

Not sure what you mean here. Are you restarting the Oculus runtime service?

Mickelukas

It sometimes happens when I have the program running and am starting up another instance of it or when I shut down the program and starting it up again really quickly. Is there some kind of shared resource?

Quote from: spasi on December 24, 2015, 07:20:23
Not sure what you mean here. Are you restarting the Oculus runtime service?
No, the JVM, sorry.

Debug output:
Quote[LWJGL] Version: 3.0.0 build 7
[LWJGL]     OS: Windows 10 v10.0
[LWJGL]    JRE: 1.8.0_66 amd64
[LWJGL]    JVM: Java HotSpot(TM) 64-Bit Server VM v25.66-b18 by Oracle Corporation
[LWJGL] Loaded library from java.library.path: lwjgl
[LWJGL] MemoryUtil accessor: MemoryAccessorUnsafe
[LWJGL] Loaded native library: C:\Users\luke_\Desktop\TTDO\lwjgl b7\native\jemalloc.dll
[LWJGL] MemoryUtil allocator: JEmallocAllocator
LibOVR
  • [1] 12/24/15 13:11:55: [CAPI] LibOVR module is located at C:\WINDOWS\SYSTEM32\LibOVRRT64_0_8.dll

    LibOVR
  • [1] 12/24/15 13:11:55: [IPC] Call Stats for SetInitialState : x1: C2S=17.8469, S2C=11.9954, Runtime=38.6194 (microseconds) C2Ssize=80, S2Csize=81 (bytes)

    LibOVR
  • [1] 12/24/15 13:11:55: [IPC] Call Stats for IsLatencyTesterAvailable : x1: C2S=10.5326, S2C=9.06972, Runtime=0.585143 (microseconds) C2Ssize=33, S2Csize=18 (bytes)

    LibOVR
  • [1] 12/24/15 13:11:55: [IPC] Call Stats for Hmd_Create : x1: C2S=13.1657, S2C=11.1177, Runtime=6.72915 (microseconds) C2Ssize=19, S2Csize=171 (bytes)

    LibOVR
  • [1] 12/24/15 13:11:55: [IPC] Call Stats for Hmd_GetHmdInfo : x1: C2S=10.5326, S2C=11.1177, Runtime=4.38857 (microseconds) C2Ssize=23, S2Csize=699 (bytes)

    LibOVR
  • [1] 12/24/15 13:11:55: [IPC] Call Stats for SetNumberValue : x1: C2S=11.1177, S2C=10.24, Runtime=2.63314 (microseconds) C2Ssize=55, S2Csize=25 (bytes)

    LibOVR
  • [1] 12/24/15 13:11:55: [IPC] Call Stats for SetNumberValues : x1: C2S=10.5326, S2C=9.65486, Runtime=2.34057 (microseconds) C2Ssize=81, S2Csize=25 (bytes)

    LibOVR
  • [1] 12/24/15 13:11:55: [IPC] Call Stats for Hmd_SetEnabledCaps : x1: C2S=10.5326, S2C=8.77715, Runtime=1.46286 (microseconds) C2Ssize=35, S2Csize=33 (bytes)

    LibOVR
  • [1] 12/24/15 13:11:55: [IPC] Call Stats for Hmd_ConfigureTracking : x1: C2S=8.77715, S2C=7.89943, Runtime=2.048 (microseconds) C2Ssize=46, S2Csize=25 (bytes)

    [LWJGL] Loaded native library: C:\Users\luke_\Desktop\TTDO\lwjgl b7\native\glfw.dll
    [LWJGL] Loaded native library: opengl32.dll
    [LWJGL] Failed to locate address for GL function glNamedBufferPageCommitmentARB
    [LWJGL] Failed to locate address for GL function glVertexWeighthNV
    [LWJGL] Failed to locate address for GL function glVertexWeighthvNV
    [LWJGL] Failed to locate address for GL function wglCopyImageSubDataNV
    [LWJGL] [GL] WGL_NV_copy_image was reported as available but an entry point is missing.
    [LWJGL] Failed to locate address for GL function glNamedBufferPageCommitmentARB
    [LWJGL] Failed to locate address for GL function glVertexWeighthNV
    [LWJGL] Failed to locate address for GL function glVertexWeighthvNV
    [LWJGL] Failed to locate address for GL function wglCopyImageSubDataNV
    [LWJGL] [GL] WGL_NV_copy_image was reported as available but an entry point is missing.
    [LWJGL] ClosureError for closure:
        at org.lwjgl.ovr.OVRLogCallback.<init>(OVRLogCallback.java:33)
        at com.stateoffortune.client.input.MyOculusRift$1.<init>(MyOculusRift.java:66)
        at com.stateoffortune.client.input.MyOculusRift.init(MyOculusRift.java:66)
        at com.stateoffortune.client.Main.main(Main.java:269)
    [LWJGL] ClosureError for closure:
        at org.lwjgl.ovr.OVRLogCallback.<init>(OVRLogCallback.java:33)
        at com.stateoffortune.client.input.MyOculusRift$1.<init>(MyOculusRift.java:66)
        at com.stateoffortune.client.input.MyOculusRift.init(MyOculusRift.java:66)
        at com.stateoffortune.client.Main.main(Main.java:269)
    [LWJGL] ClosureError for closure:
        at org.lwjgl.ovr.OVRLogCallback.<init>(OVRLogCallback.java:33)
        at com.stateoffortune.client.input.MyOculusRift$1.<init>(MyOculusRift.java:66)
        at com.stateoffortune.client.input.MyOculusRift.init(MyOculusRift.java:66)
        at com.stateoffortune.client.Main.main(Main.java:269)
    [LWJGL] Exception in closure that was invoked asynchronously from a native thread.
    org.lwjgl.system.libffi.ClosureError: Callback failed because the closure instance has been garbage collected.
Line 66 where the error is thrown is this (as per the Hello OVR code):
QuoteOVRLogCallback callback = new OVRLogCallback() {

            @Override
            public void invoke(long userData, int level, long message) {
                System.out.println("LibOVR [" + userData + "] [" + level + "] " + memDecodeASCII(message));
            }
        };

spasi

Quote from: Mickelukas on December 24, 2015, 13:16:56Line 66 where the error is thrown is this (as per the Hello OVR code):
QuoteOVRLogCallback callback = new OVRLogCallback() {

            @Override
            public void invoke(long userData, int level, long message) {
                System.out.println("LibOVR [" + userData + "] [" + level + "] " + memDecodeASCII(message));
            }
        };

The HelloLibOVR sample is very simple and doesn't try to store a reference to the callback (it does everything in a single method). Do you store it somewhere in MyOculusRift?

Mickelukas

No, and I'm running initParams.free(); in the init function to make sure I don't keep anything. Maybe it's kept in ovr_Initialize?

spasi

Yes, ovr_Initialize() copies LogCallback from the ovrInitParams struct. Otherwise you wouldn't be getting any log output. You must keep a strong reference to the OVRLogCallback instance, until ovr_Shutdown() runs.

Just to be clear: what ovr_Initialize() really copies is a pointer to the libffi closure. The closure contains a JNI weak global reference to the OVRLogCallback instance. The weak reference and the libffi closure will be deallocated when you call .release() on the OVRLogCallback instance. But nothing stops the OVRLogCallback instance itself from being GCed, unless it's strongly referenced in Java code.

Mickelukas

By adding a strong reference and making sure that callback.release(); is called after ovr_shutdown() the error is gone, thanks!