strange crash related to external texture

[raft]

i have a strange situation. i render video content to an external texture which is assigned to an Object3D (as mentioned in this thread).

i have an extra regular object in the scene which is added to world but invisible. if i make it visible after above external texture starts working, i got a crash as in the logs below.

if object is visible when external texture starts, then all is good. i can switch its visibility on and off without any problem.

what's more weirder is, i set glDebugLevel to 1 to collect some logs. but above problem never happened when logs are on.

both 3 cases are consistent behaviours, they happen all the time.

weird, huh? any ideas?

Code Select Expand

05-22 14:15:16.520: I/jPCT-AE(10446): Normal vectors calculated in 1ms!
05-22 14:15:16.575: I/jPCT-AE(10446): Subobject of object 3/object5 compiled to indexed fixed point data using 6/4 vertices in 1ms!
05-22 14:15:16.575: I/jPCT-AE(10446): Object 3/object5 compiled to 1 subobjects in 1ms!
05-22 14:15:16.575: I/jPCT-AE(10446): Compiling shader program!
05-22 14:15:16.610: I/jPCT-AE(10446): Handles of 33: 1/29/2
05-22 14:15:16.610: I/jPCT-AE(10446): Creating buffers...
05-22 14:15:16.610: I/jPCT-AE(10446): VBO created for object 'object5'
05-22 14:15:20.925: I/jPCT-AE(10446): Creating buffers...
05-22 14:15:20.925: I/jPCT-AE(10446): [ 1400757320932 ] - ERROR: before: glError 1282
05-22 14:15:20.950: W/dalvikvm(10446): threadid=11: thread exiting with uncaught exception (group=0x41ca5700)
05-22 14:15:20.955: E/AndroidRuntime(10446): FATAL EXCEPTION: GLThread 9050
05-22 14:15:20.955: E/AndroidRuntime(10446): java.lang.RuntimeException: [ 1400757320932 ] - ERROR: before: glError 1282
05-22 14:15:20.955: E/AndroidRuntime(10446): at com.threed.jpct.Logger.log(Logger.java:193)
05-22 14:15:20.955: E/AndroidRuntime(10446): at com.threed.jpct.GL20.checkError(GL20.java:152)
05-22 14:15:20.955: E/AndroidRuntime(10446): at com.threed.jpct.GL20.glGenBuffers(GL20.java:1362)
05-22 14:15:20.955: E/AndroidRuntime(10446): at com.threed.jpct.CompiledInstance.compileToVBO(CompiledInstance.java:1464)
05-22 14:15:20.955: E/AndroidRuntime(10446): at com.threed.jpct.CompiledInstance.render(CompiledInstance.java:597)
05-22 14:15:20.955: E/AndroidRuntime(10446): at com.threed.jpct.GLRenderer.drawVertexArray(GLRenderer.java:2290)
05-22 14:15:20.955: E/AndroidRuntime(10446): at com.threed.jpct.World.draw(World.java:1361)
05-22 14:15:20.955: E/AndroidRuntime(10446): at com.threed.jpct.World.draw(World.java:1099)
05-22 14:15:20.955: E/AndroidRuntime(10446): at net.arox.ar.android.demo.apps.VideoPlaneActivity$VideoPlaneView.render3D(VideoPlaneActivity.java:123)
05-22 14:15:20.955: E/AndroidRuntime(10446): at net.arox.ar.android.demo.view.JpctCameraView$OpenGLRenderer.onDrawFrame(JpctCameraView.java:361)
05-22 14:15:20.955: E/AndroidRuntime(10446): at android.opengl.GLSurfaceView$GLThread.guardedRun(GLSurfaceView.java:1531)
05-22 14:15:20.955: E/AndroidRuntime(10446): at android.opengl.GLSurfaceView$GLThread.run(GLSurfaceView.java:1248)


[EgonOlsen]

That's because something causes an INVALID_OPERATION (1282), most likely when creating the external texture. OpenGL stores errors until you ask for them. jPCT only asks for errors in some special situations, one is the creation of VBOs. So before creating one, it asks if everything is in a clean state. If you render the object before enabling the texture, the state is clean when creating the VBO for that object. If you enable the texture first, something causes that it isn't and you the exception. If you enable the gl debug mode, each and every command causes an error query, but it will be logged as a warning only. So in that case, you should see some warning in the log. Most likely directly after the first jPCT initiated gl command after the creation of the external texture.

[raft]

i couldnt find a warning in jPCT-AE logs. ie: command below prints no logs.

Code Select Expand

adb logcat -s jPCT-AE:W

i can post all logs but they are quite big. anything specific which i can search for in logs?

[EgonOlsen]

It's a jPCT Logger's kind of warning...search for "!! ERROR !!"

[raft]

here it's. at the bottom line. but the logs before it does not say anything to me?

Code Select Expand

I/jPCT-AE (22937): glLoadIdentity() took 0ns
I/jPCT-AE (22937): glFrustumf(-0.625, 0.625, -0.3515625, 0.3515625, 1.0, 10000.0) took 0ns
I/jPCT-AE (22937): glEnable(2977) took 61041ns
I/jPCT-AE (22937): glEnable(2896) took 30520ns
I/jPCT-AE (22937): glEnable(2884) took 244163ns
I/jPCT-AE (22937): glActiveTexture(33984) took 0ns
I/jPCT-AE (22937): glBindTexture(36197, 1) took 671448ns
I/jPCT-AE (22937): glMatrixMode(5888) took 30520ns
I/jPCT-AE (22937): glPushMatrix() took 0ns
I/jPCT-AE (22937): glLoadIdentity() took 305204ns
I/jPCT-AE (22937): glLightModelfv(2899, [F@418eef38, 0) took 0ns
I/jPCT-AE (22937): glMaterialfv(1032, 5632, [F@418eef60, 0) took 30520ns
I/jPCT-AE (22937): glLoadMatrixf([F@418627e0, 0) took 0ns
I/jPCT-AE (22937): glEnableClientState(32885) took 0ns
I/jPCT-AE (22937): glBindBuffer(34962, 1) took 30520ns
I/jPCT-AE (22937): glNormalPointer(5132, 12, 0) took 0ns
I/jPCT-AE (22937): glEnableClientState(32884) took 0ns
I/jPCT-AE (22937): glBindBuffer(34962, 2) took 0ns
I/jPCT-AE (22937): glVertexPointer(3, 5132, 12, 0) took 30521ns
I/jPCT-AE (22937): glDisableClientState(32886) took 30520ns
I/jPCT-AE (22937): glClientActiveTexture(33984) took 30520ns
I/jPCT-AE (22937): glEnableClientState(32888) took 30521ns
I/jPCT-AE (22937): glBindBuffer(34962, 3) took 0ns
I/jPCT-AE (22937): glTexCoordPointer(2, 5132, 8, 0) took 30520ns
I/jPCT-AE (22937): glBindBuffer(34962, 0) took 0ns
I/jPCT-AE (22937): glBindBuffer(34963, 4) took 30520ns
I/jPCT-AE (22937): glDrawElements(4, 6, 5123, 0) took 152602ns
I/jPCT-AE (22937): glBindBuffer(34963, 0) took 0ns
I/jPCT-AE (22937): glMatrixMode(5888) took 30521ns
I/jPCT-AE (22937): glPopMatrix() took 30520ns
I/jPCT-AE (22937): glEnable(3042) took 30521ns
I/jPCT-AE (22937): glBlendFunc(770, 771) took 30521ns
I/jPCT-AE (22937): glDepthMask(false) took 30521ns
I/jPCT-AE (22937): glGenTextures(1, java.nio.IntToByteBufferAdapter, status: capacity=1 position=0 limit=1) took 30521ns
I/jPCT-AE (22937): glActiveTexture(33984) took 0ns
I/jPCT-AE (22937): glBindTexture(3553, 5) took 30520ns
I/jPCT-AE (22937): glTexParameterx(3553, 10241, 9729) took 0ns
I/jPCT-AE (22937): glTexParameterx(3553, 10240, 9729) took 30521ns
I/jPCT-AE (22937): glTexParameterx(3553, 10242, 10497) took 30520ns
I/jPCT-AE (22937): glTexParameterx(3553, 10243, 10497) took 0ns
I/jPCT-AE (22937): glTexImage2D(3553, 0, 6408, 64, 64, 0, 6408, 5121, java.nio.ReadWriteDirectByteBuffer, status: capacity=16384 position=0 limit=16384) took 396765ns
I/jPCT-AE (22937): glBindTexture(3553, 1) took 1526018ns
I/jPCT-AE (22937): [ 1400827355679 ] - WARNING: !! ERROR !! - 1282


[EgonOlsen]

So...it doesn't seem to like that texture bind. I think i know what this is...it tries to bind the former texture, but that fails because that former texture is the external one and it should use the proper gl target for that, which it doesn't. Not sure how to solve this ATM, i'll look into it.

[raft]

ok, thx. btw, you may want print log messages according to their category so they can be easily tracked, ie: debug/info/warning/error

[EgonOlsen]

Please try this jar and let me know if it helps: jpct.de/download/beta/jpct_ae.jar

I've also changed the Logger as requested.

[raft]

unfortunately :/ here are the new logs:

Code Select Expand

I/jPCT-AE (18961): glClientActiveTexture(33984) took 8667ns
I/jPCT-AE (18961): glEnableClientState(32888) took 9041ns
I/jPCT-AE (18961): glBindBuffer(34962, 3) took 9042ns
I/jPCT-AE (18961): glTexCoordPointer(2, 5132, 8, 0) took 10542ns
I/jPCT-AE (18961): glBindBuffer(34962, 0) took 7458ns
I/jPCT-AE (18961): glBindBuffer(34963, 4) took 9041ns
I/jPCT-AE (18961): glDrawElements(4, 6, 5123, 0) took 52709ns
I/jPCT-AE (18961): glBindBuffer(34963, 0) took 8708ns
I/jPCT-AE (18961): glMatrixMode(5888) took 5583ns
I/jPCT-AE (18961): glPopMatrix() took 5458ns
I/jPCT-AE (18961): glEnable(3042) took 10167ns
I/jPCT-AE (18961): glBlendFunc(770, 771) took 10792ns
I/jPCT-AE (18961): glDepthMask(false) took 19292ns
I/jPCT-AE (18961): glGenTextures(1, java.nio.ByteBufferAsIntBuffer[position=0,limit=1,capacity=1]) took 20459ns
I/jPCT-AE (18961): glActiveTexture(33984) took 9625ns
I/jPCT-AE (18961): glBindTexture(3553, 5) took 18500ns
I/jPCT-AE (18961): glTexParameterx(3553, 10241, 9729) took 10833ns
I/jPCT-AE (18961): glTexParameterx(3553, 10240, 9729) took 8042ns
I/jPCT-AE (18961): glTexParameterx(3553, 10242, 10497) took 8167ns
I/jPCT-AE (18961): glTexParameterx(3553, 10243, 10497) took 7916ns
I/jPCT-AE (18961): glTexImage2D(3553, 0, 6408, 64, 64, 0, 6408, 5121, java.nio.DirectByteBuffer[position=0,limit=16384,capacity=16384]) took 68417ns
I/jPCT-AE (18961): glBindTexture(3553, 4) took 8959ns
W/jPCT-AE (18961): [ 1401087110763 ] - WARNING: !! ERROR !! - 1282


[EgonOlsen]

Can you verify that the last parameter of the bind call here (the 4 in this case)

Code Select Expand


I/jPCT-AE (18961): glBindTexture(3553, 4) took 8959ns
W/jPCT-AE (18961): [ 1401087110763 ] - WARNING: !! ERROR !! - 1282


is the id of the external texture?

[raft]

no it's not.

Code Select Expand

W/jPCT-AE (24951): [ 1401092248033 ] - WARNING: textId: 1

Code Select Expand

I/jPCT-AE (24951): glBindTexture(3553, 4) took 10292ns
W/jPCT-AE (24951): [ 1401092243321 ] - WARNING: !! ERROR !! - 1282


[raft]

sorry, there are two TextureRenderer classes in this case. one uses external texture and other direct buffer.
and yes that 4 is the id of external texture.

Code Select Expand

W/jPCT-AE (26517): [ 1401092777020 ] - WARNING: textId: 4

Code Select Expand

I/jPCT-AE (26517): glBindTexture(3553, 4) took 8916ns
W/jPCT-AE (26517): [ 1401092777014 ] - WARNING: !! ERROR !! - 1282


[EgonOlsen]

Strange... it should actually use the correct gl target now, but it still uses GL_TEXTURE_2D...i'll look into it later...

[EgonOlsen]

Oops, i think that my logic was a little twisted...i've updated the jar, please try again.

[raft]

yes, it's solved now. thx