Screen flickers then whole phone freezes

Started by kkl, May 11, 2014, 04:38:58 PM

Previous topic - Next topic

kkl

I have an issue where the screen flicker when moving the camera around. It flickers in such a way that you see half of the screen shows one frame and another half of screen shows another frame. The strangest is, it only happens at certain locations when moving the camera. If we move the camera away from that point, it'll be ok. If we leave it flickering, it just freezes the entire phone. Has anyone have this issue before?

EgonOlsen

Sounds like a race condition between two threads to me. Make sure that updating the 3d camera and view either happens in the rendering thread or is at least properly synchronized with it.

kkl

I think it would be between the camera and the android touch input event. I used a blocking array list to insert inputs and retrieve back the inputs to apply to camera location during onDrawFrame(). If they race, does it affect the phone and even freezes it? The blocking array list should be able to synchronize, isn't it? I might have missed something... I had the dead lock issue before and when I press home and it still go back to homescreen. Just the app freezes.

EgonOlsen

A race condition might freeze the phone, but it's not very likely. Maybe it's a kind of driver bug then...have you tried to reproduce it on another device with another gpu?

kkl

I don't have much devices, but i did tried it out in s3 though. The result is the same. The strange thing is, it happens at certain location and when there is animated model came into the screen at that location, it somewhat fix the problem. Can it be that the model slows down the process at each frame and buy them some time for the race condition to finish?

EgonOlsen

#5
Maybe, but if it's that a persitant problem, it doesn't sound like a threading issue.  Can you capture the effect on a screen shot and/or provide an apk so that i can see it for myself?

kkl


EgonOlsen

...that looks really strange... :o Looks like as if something is fiddling around with the gl context while the rendering happens. This is a LWP? If so, make sure that not two instances of that custom gl renderer are running. I dimly remember that to be a problem in the past with some implementations. It might help to see jPCT's log output with the Logger set to debug.
Another thing that's worth a try is to add a FrameBuffer.sync()-call at the end and/or the start of the rendering.

kkl

#8
It happens on LWP and normal app as well. I set the activity to handle by itself using android:configChanges="keyboardHidden|orientation|screenSize"

and create the renderer by this condition:

if (renderer == null || renderer.isDisposed())
renderer = new SceneSettingRenderer(getBaseContext())


isDisposed() is set to true if activity calls onDestroyed(). I tried with the sync() at start/end/start-end and disable the touch input so no race happens between onTouchEvent() and onDrawFrame(), but the issue still there.

Here's the log you might wanna have a look:
05-13 10:53:10.550: I/jPCT-AE(8385): Visibility lists disposed!
05-13 10:53:10.550: I/jPCT-AE(8385): [ 1399949590553 ] - WARNING: Unable to dispose gl related resources because the current context has changed!
05-13 10:53:10.550: I/jPCT-AE(8385): Renderer disposed!
05-13 10:53:10.550: I/jPCT-AE(8385): GLRenderer disposed with id 1 on Thread[GLThread 614,5,main]
05-13 10:53:10.550: I/jPCT-AE(8385): GLRenderer created with id 2 on Thread[GLThread 614,5,main]
05-13 10:53:10.550: I/jPCT-AE(8385): GL context is 1125358744
05-13 10:53:10.550: I/jPCT-AE(8385): Initializing GL20 render pipeline...
05-13 10:53:10.550: I/jPCT-AE(8385): Loading default shaders !
05-13 10:53:10.550: I/jPCT-AE(8385): 0 shaders in replacement map!
05-13 10:53:10.550: I/jPCT-AE(8385): Default fragment shader is: /defaultFragmentShader.src
05-13 10:53:10.550: I/jPCT-AE(8385): Loading file from InputStream
05-13 10:53:10.550: I/jPCT-AE(8385): Text file from InputStream loaded...2416 bytes
05-13 10:53:10.550: I/jPCT-AE(8385): Default vertex shader is: /defaultVertexShader.src
05-13 10:53:10.550: I/jPCT-AE(8385): Loading file from InputStream
05-13 10:53:10.550: I/jPCT-AE(8385): Text file from InputStream loaded...4496 bytes
05-13 10:53:10.555: I/jPCT-AE(8385): Compiling shader program!
05-13 10:53:10.700: D/AbsListView(8385): onDetachedFromWindow
05-13 10:53:10.700: D/AbsListView(8385): unregisterIRListener() is called
05-13 10:53:10.800: I/jPCT-AE(8385): Handles of 210003: 4/44/5
05-13 10:53:10.800: I/jPCT-AE(8385): Loading default shaders (Tex0Amb)!
05-13 10:53:10.800: I/jPCT-AE(8385): 0 shaders in replacement map!
05-13 10:53:10.800: I/jPCT-AE(8385): Default fragment shader is: /defaultFragmentShader.src
05-13 10:53:10.800: I/jPCT-AE(8385): Loading file from InputStream
05-13 10:53:10.805: I/jPCT-AE(8385): Text file from InputStream loaded...199 bytes
05-13 10:53:10.805: I/jPCT-AE(8385): Default vertex shader is: /defaultVertexShader.src
05-13 10:53:10.805: I/jPCT-AE(8385): Loading file from InputStream
05-13 10:53:10.805: I/jPCT-AE(8385): Text file from InputStream loaded...757 bytes
05-13 10:53:10.805: I/jPCT-AE(8385): Compiling shader program!
05-13 10:53:10.805: I/jPCT-AE(8385): Handles of 420006: 1/5/2
05-13 10:53:10.805: I/jPCT-AE(8385): Loading default shaders (Tex0)!
05-13 10:53:10.805: I/jPCT-AE(8385): 0 shaders in replacement map!
05-13 10:53:10.805: I/jPCT-AE(8385): Default fragment shader is: /defaultFragmentShader.src
05-13 10:53:10.805: I/jPCT-AE(8385): Loading file from InputStream
05-13 10:53:10.805: I/jPCT-AE(8385): Text file from InputStream loaded...201 bytes
05-13 10:53:10.805: I/jPCT-AE(8385): Default vertex shader is: /defaultVertexShader.src
05-13 10:53:10.805: I/jPCT-AE(8385): Loading file from InputStream
05-13 10:53:10.805: I/jPCT-AE(8385): Text file from InputStream loaded...4020 bytes
05-13 10:53:10.805: I/jPCT-AE(8385): Compiling shader program!
05-13 10:53:10.985: I/jPCT-AE(8385): Handles of 630009: 1/41/2
05-13 10:53:10.985: I/jPCT-AE(8385): Loading default shaders (Tex1)!
05-13 10:53:10.985: I/jPCT-AE(8385): 0 shaders in replacement map!
05-13 10:53:10.985: I/jPCT-AE(8385): Default fragment shader is: /defaultFragmentShader.src
05-13 10:53:10.985: I/jPCT-AE(8385): Loading file from InputStream
05-13 10:53:10.985: I/jPCT-AE(8385): Text file from InputStream loaded...997 bytes
05-13 10:53:10.985: I/jPCT-AE(8385): Default vertex shader is: /defaultVertexShader.src
05-13 10:53:10.990: I/jPCT-AE(8385): Loading file from InputStream
05-13 10:53:10.990: I/jPCT-AE(8385): Text file from InputStream loaded...4390 bytes
05-13 10:53:10.990: I/jPCT-AE(8385): Compiling shader program!
05-13 10:53:11.165: I/jPCT-AE(8385): Handles of 840012: 2/44/3
05-13 10:53:11.165: I/jPCT-AE(8385): Loading default shaders (Tex0Light0)!
05-13 10:53:11.165: I/jPCT-AE(8385): 0 shaders in replacement map!
05-13 10:53:11.165: I/jPCT-AE(8385): Default fragment shader is: /defaultFragmentShader.src
05-13 10:53:11.170: I/jPCT-AE(8385): Loading file from InputStream
05-13 10:53:11.170: I/jPCT-AE(8385): Text file from InputStream loaded...201 bytes
05-13 10:53:11.170: I/jPCT-AE(8385): Default vertex shader is: /defaultVertexShader.src
05-13 10:53:11.170: I/jPCT-AE(8385): Loading file from InputStream
05-13 10:53:11.170: I/jPCT-AE(8385): Text file from InputStream loaded...1293 bytes
05-13 10:53:11.170: I/jPCT-AE(8385): Compiling shader program!
05-13 10:53:11.170: I/jPCT-AE(8385): Handles of 1050015: 1/11/2
05-13 10:53:11.175: I/jPCT-AE(8385): Loading default shaders (Fog)!
05-13 10:53:11.175: I/jPCT-AE(8385): 0 shaders in replacement map!
05-13 10:53:11.175: I/jPCT-AE(8385): Default fragment shader is: /defaultFragmentShader.src
05-13 10:53:11.175: I/jPCT-AE(8385): Loading file from InputStream
05-13 10:53:11.175: I/jPCT-AE(8385): Text file from InputStream loaded...328 bytes
05-13 10:53:11.175: I/jPCT-AE(8385): Default vertex shader is: /defaultVertexShader.src
05-13 10:53:11.175: I/jPCT-AE(8385): Loading file from InputStream
05-13 10:53:11.175: I/jPCT-AE(8385): Text file from InputStream loaded...4267 bytes
05-13 10:53:11.175: I/jPCT-AE(8385): Compiling shader program!
05-13 10:53:11.340: I/jPCT-AE(8385): Handles of 1260018: 1/44/2
05-13 10:53:11.340: I/jPCT-AE(8385): Loading default shaders (FogLight0)!
05-13 10:53:11.340: I/jPCT-AE(8385): 0 shaders in replacement map!
05-13 10:53:11.340: I/jPCT-AE(8385): Default fragment shader is: /defaultFragmentShader.src
05-13 10:53:11.340: I/jPCT-AE(8385): Loading file from InputStream
05-13 10:53:11.340: I/jPCT-AE(8385): Text file from InputStream loaded...328 bytes
05-13 10:53:11.340: I/jPCT-AE(8385): Default vertex shader is: /defaultVertexShader.src
05-13 10:53:11.340: I/jPCT-AE(8385): Loading file from InputStream
05-13 10:53:11.340: I/jPCT-AE(8385): Text file from InputStream loaded...1608 bytes
05-13 10:53:11.340: I/jPCT-AE(8385): Compiling shader program!
05-13 10:53:11.345: I/jPCT-AE(8385): Handles of 1470021: 1/15/2
05-13 10:53:11.345: I/jPCT-AE(8385): Loading default shaders (Depth)!
05-13 10:53:11.345: I/jPCT-AE(8385): 0 shaders in replacement map!
05-13 10:53:11.345: I/jPCT-AE(8385): Default fragment shader is: /defaultFragmentShader.src
05-13 10:53:11.345: I/jPCT-AE(8385): Loading file from InputStream
05-13 10:53:11.345: I/jPCT-AE(8385): Text file from InputStream loaded...745 bytes
05-13 10:53:11.345: I/jPCT-AE(8385): Default vertex shader is: /defaultVertexShader.src
05-13 10:53:11.345: I/jPCT-AE(8385): Loading file from InputStream
05-13 10:53:11.345: I/jPCT-AE(8385): Text file from InputStream loaded...248 bytes
05-13 10:53:11.345: I/jPCT-AE(8385): Compiling shader program!
05-13 10:53:11.360: I/jPCT-AE(8385): Handles of 1680024: 1/1/-1
05-13 10:53:11.360: I/jPCT-AE(8385): GL20 render pipeline initialized!
05-13 10:53:11.365: I/jPCT-AE(8385): OpenGL vendor:     Imagination Technologies
05-13 10:53:11.365: I/jPCT-AE(8385): OpenGL renderer:   PowerVR SGX 544MP
05-13 10:53:11.365: I/jPCT-AE(8385): OpenGL version:    OpenGL ES 2.0 build 1.10@2359475
05-13 10:53:11.365: I/jPCT-AE(8385): OpenGL renderer initialized (using 3/8 texture stages)
05-13 10:53:11.365: I/jPCT-AE(8385): Allocating native memory for 16*16 texture(true/false/false/false/): 1024 bytes!
05-13 10:53:11.365: I/jPCT-AE(8385): Creating texture buffer of size 256
05-13 10:53:11.365: I/jPCT-AE(8385): New texture's id is: 70001
05-13 10:53:11.365: I/jPCT-AE(8385): Creating texture buffer of size 64
05-13 10:53:11.365: I/jPCT-AE(8385): Creating texture buffer of size 16
05-13 10:53:11.365: I/jPCT-AE(8385): Creating texture buffer of size 4
05-13 10:53:11.365: I/jPCT-AE(8385): Creating texture buffer of size 1
05-13 10:53:11.365: I/jPCT-AE(8385): Mipmaps generated by the CPU in 0ms
05-13 10:53:11.365: I/jPCT-AE(8385): New texture uploaded: com.threed.jpct.Texture@42b15228 in thread Thread[GLThread 614,5,main]
05-13 10:53:11.365: I/jPCT-AE(8385): Retrieved texture data from disk!
05-13 10:53:11.365: I/jPCT-AE(8385): Allocating native memory for 128*128 texture(true/false/false/false/): 65536 bytes!
05-13 10:53:11.365: I/jPCT-AE(8385): Creating texture buffer of size 16384
05-13 10:53:11.365: I/jPCT-AE(8385): New texture's id is: 140002
05-13 10:53:11.365: I/jPCT-AE(8385): Creating texture buffer of size 4096
05-13 10:53:11.365: I/jPCT-AE(8385): Creating texture buffer of size 1024
05-13 10:53:11.365: I/jPCT-AE(8385): Creating texture buffer of size 256
05-13 10:53:11.365: I/jPCT-AE(8385): Creating texture buffer of size 64
05-13 10:53:11.365: I/jPCT-AE(8385): Creating texture buffer of size 16
05-13 10:53:11.370: I/jPCT-AE(8385): Creating texture buffer of size 4
05-13 10:53:11.370: I/jPCT-AE(8385): Creating texture buffer of size 1
05-13 10:53:11.370: I/jPCT-AE(8385): Mipmaps generated by the CPU in 2ms
05-13 10:53:11.370: I/jPCT-AE(8385): New texture uploaded: com.threed.jpct.Texture@42ca0e98 in thread Thread[GLThread 614,5,main]
05-13 10:53:11.370: I/jPCT-AE(8385): Retrieved texture data from disk!
05-13 10:53:11.370: I/jPCT-AE(8385): Allocating native memory for 128*128 texture(true/false/false/false/): 65536 bytes!
05-13 10:53:11.370: I/jPCT-AE(8385): Creating texture buffer of size 16384
05-13 10:53:11.370: I/jPCT-AE(8385): New texture's id is: 210003
05-13 10:53:11.370: I/jPCT-AE(8385): New texture uploaded: com.threed.jpct.Texture@42ce2e00 in thread Thread[GLThread 614,5,main]
05-13 10:53:11.370: I/jPCT-AE(8385): Retrieved texture data from disk!
05-13 10:53:11.370: I/jPCT-AE(8385): [ 1399949591376 ] - WARNING: Texture's size is 128/32, but textures should be square for OpenGL ES2.0! This may result in a black texture!
05-13 10:53:11.370: I/jPCT-AE(8385): Allocating native memory for 128*32 texture(true/false/false/false/): 8192 bytes!
05-13 10:53:11.370: I/jPCT-AE(8385): Creating texture buffer of size 2048
05-13 10:53:11.375: I/jPCT-AE(8385): New texture's id is: 280004
05-13 10:53:11.375: I/jPCT-AE(8385): New texture uploaded: com.threed.jpct.Texture@42d0c318 in thread Thread[GLThread 614,5,main]
05-13 10:53:11.375: I/jPCT-AE(8385): Retrieved texture data from disk!
05-13 10:53:11.375: I/jPCT-AE(8385): [ 1399949591378 ] - WARNING: Texture's size is 32/16, but textures should be square for OpenGL ES2.0! This may result in a black texture!
05-13 10:53:11.375: I/jPCT-AE(8385): Allocating native memory for 32*16 texture(true/false/false/false/): 1024 bytes!
05-13 10:53:11.375: I/jPCT-AE(8385): Creating texture buffer of size 256
05-13 10:53:11.375: I/jPCT-AE(8385): New texture's id is: 350005
05-13 10:53:11.375: I/jPCT-AE(8385): New texture uploaded: com.threed.jpct.Texture@42d16868 in thread Thread[GLThread 614,5,main]
05-13 10:53:11.400: D/dalvikvm(8385): GC_FOR_ALLOC freed 1116K, 47% free 22092K/41088K, paused 26ms, total 27ms
05-13 10:53:11.405: D/AbsListView(8385): [unregisterDoubleTapMotionListener]
05-13 10:53:11.410: I/MotionRecognitionManager(8385):   .unregisterListener : / listener count = 0->0, 
05-13 10:53:11.410: D/AbsListView(8385): unregisterIRListener() is called
05-13 10:53:11.435: D/dalvikvm(8385): GC_FOR_ALLOC freed 877K, 46% free 22240K/41088K, paused 23ms, total 23ms
05-13 10:53:11.460: D/dalvikvm(8385): GC_FOR_ALLOC freed <1K, 44% free 23264K/41088K, paused 22ms, total 22ms
05-13 10:53:11.470: I/jPCT-AE(8385): Retrieved texture data from disk!
05-13 10:53:11.470: I/jPCT-AE(8385): Allocating native memory for 512*512 texture(true/true/false/false/): 1048576 bytes!
05-13 10:53:11.475: I/jPCT-AE(8385): Creating texture buffer of size 262144
05-13 10:53:11.485: I/jPCT-AE(8385): New texture's id is: 420006
05-13 10:53:11.485: I/jPCT-AE(8385): Compressing texture (512*512) to ETC1...
05-13 10:53:11.485: I/jPCT-AE(8385): Loaded etc1_0_4123692934098.tex from cache!
05-13 10:53:11.490: I/jPCT-AE(8385): ...done in 6/5ms
05-13 10:53:11.490: I/jPCT-AE(8385): Creating texture buffer of size 65536
05-13 10:53:11.495: I/jPCT-AE(8385): Compressing texture (256*256) to ETC1...
05-13 10:53:11.495: I/jPCT-AE(8385): Loaded etc1_1_257828107436.tex from cache!
05-13 10:53:11.495: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.495: I/jPCT-AE(8385): Creating texture buffer of size 16384
05-13 10:53:11.495: I/jPCT-AE(8385): Compressing texture (128*128) to ETC1...
05-13 10:53:11.495: I/jPCT-AE(8385): Loaded etc1_2_16138487139.tex from cache!
05-13 10:53:11.495: I/jPCT-AE(8385): ...done in 1/0ms
05-13 10:53:11.495: I/jPCT-AE(8385): Creating texture buffer of size 4096
05-13 10:53:11.500: I/jPCT-AE(8385): Compressing texture (64*64) to ETC1...
05-13 10:53:11.500: I/jPCT-AE(8385): Loaded etc1_3_1014693436.tex from cache!
05-13 10:53:11.500: I/jPCT-AE(8385): ...done in 1/0ms
05-13 10:53:11.500: I/jPCT-AE(8385): Creating texture buffer of size 1024
05-13 10:53:11.500: I/jPCT-AE(8385): Compressing texture (32*32) to ETC1...
05-13 10:53:11.500: I/jPCT-AE(8385): Loaded etc1_4_64926968.tex from cache!
05-13 10:53:11.500: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.500: I/jPCT-AE(8385): Creating texture buffer of size 256
05-13 10:53:11.500: I/jPCT-AE(8385): Compressing texture (16*16) to ETC1...
05-13 10:53:11.500: I/jPCT-AE(8385): Loaded etc1_5_4430013.tex from cache!
05-13 10:53:11.500: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.500: I/jPCT-AE(8385): Creating texture buffer of size 64
05-13 10:53:11.500: I/jPCT-AE(8385): Compressing texture (8*8) to ETC1...
05-13 10:53:11.500: I/jPCT-AE(8385): Loaded etc1_6_375948.tex from cache!
05-13 10:53:11.500: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.500: I/jPCT-AE(8385): Creating texture buffer of size 16
05-13 10:53:11.500: I/jPCT-AE(8385): Compressing texture (4*4) to ETC1...
05-13 10:53:11.500: I/jPCT-AE(8385): Loaded etc1_7_45931.tex from cache!
05-13 10:53:11.500: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.500: I/jPCT-AE(8385): Creating texture buffer of size 4
05-13 10:53:11.500: I/jPCT-AE(8385): Compressing texture (2*2) to ETC1...
05-13 10:53:11.500: I/jPCT-AE(8385): Loaded etc1_8_16948.tex from cache!
05-13 10:53:11.500: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.500: I/jPCT-AE(8385): Creating texture buffer of size 1
05-13 10:53:11.500: I/jPCT-AE(8385): Compressing texture (1*1) to ETC1...
05-13 10:53:11.500: I/jPCT-AE(8385): Loaded etc1_9_16473.tex from cache!
05-13 10:53:11.500: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.500: I/jPCT-AE(8385): Mipmaps generated by the CPU in 17ms
05-13 10:53:11.500: I/jPCT-AE(8385): New texture uploaded: com.threed.jpct.Texture@42b10a58 in thread Thread[GLThread 614,5,main]
05-13 10:53:11.520: D/dalvikvm(8385): GC_FOR_ALLOC freed 6203K, 44% free 23265K/41088K, paused 13ms, total 13ms
05-13 10:53:11.525: I/jPCT-AE(8385): Retrieved texture data from disk!
05-13 10:53:11.525: I/jPCT-AE(8385): Allocating native memory for 512*512 texture(true/true/false/false/): 1048576 bytes!
05-13 10:53:11.530: I/jPCT-AE(8385): Creating texture buffer of size 262144
05-13 10:53:11.540: D/dalvikvm(8385): GC_FOR_ALLOC freed 2051K, 44% free 23262K/41088K, paused 12ms, total 12ms
05-13 10:53:11.545: I/jPCT-AE(8385): New texture's id is: 490007
05-13 10:53:11.545: I/jPCT-AE(8385): Compressing texture (512*512) to ETC1...
05-13 10:53:11.545: I/jPCT-AE(8385): Loaded etc1_0_4123713749042.tex from cache!
05-13 10:53:11.545: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.545: I/jPCT-AE(8385): Creating texture buffer of size 65536
05-13 10:53:11.550: I/jPCT-AE(8385): Compressing texture (256*256) to ETC1...
05-13 10:53:11.550: I/jPCT-AE(8385): Loaded etc1_1_257833308256.tex from cache!
05-13 10:53:11.550: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.550: I/jPCT-AE(8385): Creating texture buffer of size 16384
05-13 10:53:11.555: I/jPCT-AE(8385): Compressing texture (128*128) to ETC1...
05-13 10:53:11.555: I/jPCT-AE(8385): Loaded etc1_2_16139342772.tex from cache!
05-13 10:53:11.555: I/jPCT-AE(8385): ...done in 1/0ms
05-13 10:53:11.555: I/jPCT-AE(8385): Creating texture buffer of size 4096
05-13 10:53:11.555: I/jPCT-AE(8385): Compressing texture (64*64) to ETC1...
05-13 10:53:11.555: I/jPCT-AE(8385): Loaded etc1_3_1014775409.tex from cache!
05-13 10:53:11.555: I/jPCT-AE(8385): ...done in 1/0ms
05-13 10:53:11.555: I/jPCT-AE(8385): Creating texture buffer of size 1024
05-13 10:53:11.555: I/jPCT-AE(8385): Compressing texture (32*32) to ETC1...
05-13 10:53:11.555: I/jPCT-AE(8385): Loaded etc1_4_64925054.tex from cache!
05-13 10:53:11.560: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.560: I/jPCT-AE(8385): Creating texture buffer of size 256
05-13 10:53:11.560: I/jPCT-AE(8385): Compressing texture (16*16) to ETC1...
05-13 10:53:11.560: I/jPCT-AE(8385): Loaded etc1_5_4421730.tex from cache!
05-13 10:53:11.560: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.560: I/jPCT-AE(8385): Creating texture buffer of size 64
05-13 10:53:11.560: I/jPCT-AE(8385): Compressing texture (8*8) to ETC1...
05-13 10:53:11.560: I/jPCT-AE(8385): Loaded etc1_6_372702.tex from cache!
05-13 10:53:11.560: I/jPCT-AE(8385): ...done in 1/0ms
05-13 10:53:11.560: I/jPCT-AE(8385): Creating texture buffer of size 16
05-13 10:53:11.560: I/jPCT-AE(8385): Compressing texture (4*4) to ETC1...
05-13 10:53:11.560: I/jPCT-AE(8385): Loaded etc1_7_44506.tex from cache!
05-13 10:53:11.560: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.560: I/jPCT-AE(8385): Creating texture buffer of size 4
05-13 10:53:11.565: I/jPCT-AE(8385): Compressing texture (2*2) to ETC1...
05-13 10:53:11.565: I/jPCT-AE(8385): Loaded etc1_8_16623.tex from cache!
05-13 10:53:11.565: I/jPCT-AE(8385): ...done in 1/0ms
05-13 10:53:11.565: I/jPCT-AE(8385): Creating texture buffer of size 1
05-13 10:53:11.565: I/jPCT-AE(8385): Compressing texture (1*1) to ETC1...
05-13 10:53:11.565: I/jPCT-AE(8385): Loaded etc1_9_16473.tex from cache!
05-13 10:53:11.565: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.565: I/jPCT-AE(8385): Mipmaps generated by the CPU in 19ms
05-13 10:53:11.565: I/jPCT-AE(8385): New texture uploaded: com.threed.jpct.Texture@42b011a8 in thread Thread[GLThread 614,5,main]
05-13 10:53:11.565: I/jPCT-AE(8385): Retrieved texture data from disk!
05-13 10:53:11.565: I/jPCT-AE(8385): Allocating native memory for 64*64 texture(true/true/false/false/): 16384 bytes!
05-13 10:53:11.580: D/dalvikvm(8385): GC_FOR_ALLOC freed 4188K, 49% free 21231K/41088K, paused 13ms, total 13ms
05-13 10:53:11.580: I/jPCT-AE(8385): Creating texture buffer of size 4096
05-13 10:53:11.580: I/jPCT-AE(8385): New texture's id is: 560008
05-13 10:53:11.580: I/jPCT-AE(8385): Compressing texture (64*64) to ETC1...
05-13 10:53:11.580: I/jPCT-AE(8385): Loaded etc1_0_1015110426.tex from cache!
05-13 10:53:11.580: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.580: I/jPCT-AE(8385): Creating texture buffer of size 1024
05-13 10:53:11.580: I/jPCT-AE(8385): Compressing texture (32*32) to ETC1...
05-13 10:53:11.580: I/jPCT-AE(8385): Loaded etc1_1_65013169.tex from cache!
05-13 10:53:11.580: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.580: I/jPCT-AE(8385): Creating texture buffer of size 256
05-13 10:53:11.580: I/jPCT-AE(8385): Compressing texture (16*16) to ETC1...
05-13 10:53:11.585: I/jPCT-AE(8385): Loaded etc1_2_4439273.tex from cache!
05-13 10:53:11.585: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.585: I/jPCT-AE(8385): Creating texture buffer of size 64
05-13 10:53:11.585: I/jPCT-AE(8385): Compressing texture (8*8) to ETC1...
05-13 10:53:11.585: I/jPCT-AE(8385): Loaded etc1_3_372578.tex from cache!
05-13 10:53:11.585: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.585: I/jPCT-AE(8385): Creating texture buffer of size 16
05-13 10:53:11.585: I/jPCT-AE(8385): Compressing texture (4*4) to ETC1...
05-13 10:53:11.585: I/jPCT-AE(8385): Loaded etc1_4_40660.tex from cache!
05-13 10:53:11.585: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.585: I/jPCT-AE(8385): Creating texture buffer of size 4
05-13 10:53:11.585: I/jPCT-AE(8385): Compressing texture (2*2) to ETC1...
05-13 10:53:11.585: I/jPCT-AE(8385): Loaded etc1_5_11709.tex from cache!
05-13 10:53:11.585: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.585: I/jPCT-AE(8385): Creating texture buffer of size 1
05-13 10:53:11.585: I/jPCT-AE(8385): Compressing texture (1*1) to ETC1...
05-13 10:53:11.585: I/jPCT-AE(8385): Loaded etc1_6_11130.tex from cache!
05-13 10:53:11.585: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.585: I/jPCT-AE(8385): Mipmaps generated by the CPU in 6ms
05-13 10:53:11.585: I/jPCT-AE(8385): New texture uploaded: com.threed.jpct.Texture@42a7c2d8 in thread Thread[GLThread 614,5,main]
05-13 10:53:11.605: D/dalvikvm(8385): GC_FOR_ALLOC freed 104K, 46% free 22241K/41088K, paused 12ms, total 12ms
05-13 10:53:11.615: D/dalvikvm(8385): GC_FOR_ALLOC freed <1K, 44% free 23264K/41088K, paused 13ms, total 13ms
05-13 10:53:11.625: I/jPCT-AE(8385): Retrieved texture data from disk!
05-13 10:53:11.625: I/jPCT-AE(8385): Allocating native memory for 512*512 texture(true/true/false/false/): 1048576 bytes!
05-13 10:53:11.625: I/jPCT-AE(8385): Creating texture buffer of size 262144
05-13 10:53:11.630: I/jPCT-AE(8385): New texture's id is: 630009
05-13 10:53:11.630: I/jPCT-AE(8385): Compressing texture (512*512) to ETC1...
05-13 10:53:11.630: I/jPCT-AE(8385): Loaded etc1_0_4123721231787.tex from cache!
05-13 10:53:11.630: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.630: I/jPCT-AE(8385): Creating texture buffer of size 65536
05-13 10:53:11.635: I/jPCT-AE(8385): Compressing texture (256*256) to ETC1...
05-13 10:53:11.635: I/jPCT-AE(8385): Loaded etc1_1_257835499821.tex from cache!
05-13 10:53:11.635: I/jPCT-AE(8385): ...done in 1/0ms
05-13 10:53:11.635: I/jPCT-AE(8385): Creating texture buffer of size 16384
05-13 10:53:11.640: I/jPCT-AE(8385): Compressing texture (128*128) to ETC1...
05-13 10:53:11.640: I/jPCT-AE(8385): Loaded etc1_2_16140396311.tex from cache!
05-13 10:53:11.640: I/jPCT-AE(8385): ...done in 1/0ms
05-13 10:53:11.640: I/jPCT-AE(8385): Creating texture buffer of size 4096
05-13 10:53:11.640: I/jPCT-AE(8385): Compressing texture (64*64) to ETC1...
05-13 10:53:11.640: I/jPCT-AE(8385): Loaded etc1_3_1015172985.tex from cache!
05-13 10:53:11.640: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.640: I/jPCT-AE(8385): Creating texture buffer of size 1024
05-13 10:53:11.640: I/jPCT-AE(8385): Compressing texture (32*32) to ETC1...
05-13 10:53:11.640: I/jPCT-AE(8385): Loaded etc1_4_65050486.tex from cache!
05-13 10:53:11.640: I/jPCT-AE(8385): ...done in 1/0ms
05-13 10:53:11.640: I/jPCT-AE(8385): Creating texture buffer of size 256
05-13 10:53:11.640: I/jPCT-AE(8385): Compressing texture (16*16) to ETC1...
05-13 10:53:11.640: I/jPCT-AE(8385): Loaded etc1_5_4458828.tex from cache!
05-13 10:53:11.640: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.640: I/jPCT-AE(8385): Creating texture buffer of size 64
05-13 10:53:11.640: I/jPCT-AE(8385): Compressing texture (8*8) to ETC1...
05-13 10:53:11.645: I/jPCT-AE(8385): Loaded etc1_6_384069.tex from cache!
05-13 10:53:11.645: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.645: I/jPCT-AE(8385): Creating texture buffer of size 16
05-13 10:53:11.645: I/jPCT-AE(8385): Compressing texture (4*4) to ETC1...
05-13 10:53:11.645: I/jPCT-AE(8385): Loaded etc1_7_47774.tex from cache!
05-13 10:53:11.645: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.645: I/jPCT-AE(8385): Creating texture buffer of size 4
05-13 10:53:11.645: I/jPCT-AE(8385): Compressing texture (2*2) to ETC1...
05-13 10:53:11.645: I/jPCT-AE(8385): Loaded etc1_8_17371.tex from cache!
05-13 10:53:11.645: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.645: I/jPCT-AE(8385): Creating texture buffer of size 1
05-13 10:53:11.645: I/jPCT-AE(8385): Compressing texture (1*1) to ETC1...
05-13 10:53:11.645: I/jPCT-AE(8385): Loaded etc1_9_16473.tex from cache!
05-13 10:53:11.645: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.645: I/jPCT-AE(8385): Mipmaps generated by the CPU in 14ms
05-13 10:53:11.645: I/jPCT-AE(8385): New texture uploaded: com.threed.jpct.Texture@42d172c8 in thread Thread[GLThread 614,5,main]
05-13 10:53:11.645: I/jPCT-AE(8385): Retrieved texture data from disk!
05-13 10:53:11.645: I/jPCT-AE(8385): Allocating native memory for 128*128 texture(true/false/false/false/): 65536 bytes!
05-13 10:53:11.645: I/jPCT-AE(8385): Creating texture buffer of size 16384
05-13 10:53:11.645: I/jPCT-AE(8385): New texture's id is: 700010
05-13 10:53:11.645: I/jPCT-AE(8385): New texture uploaded: com.threed.jpct.Texture@42d1a820 in thread Thread[GLThread 614,5,main]
05-13 10:53:11.645: I/jPCT-AE(8385): Retrieved texture data from disk!
05-13 10:53:11.645: I/jPCT-AE(8385): Allocating native memory for 32*32 texture(true/true/false/false/): 4096 bytes!
05-13 10:53:11.650: I/jPCT-AE(8385): Creating texture buffer of size 1024
05-13 10:53:11.650: I/jPCT-AE(8385): New texture's id is: 770011
05-13 10:53:11.650: I/jPCT-AE(8385): Compressing texture (32*32) to ETC1...
05-13 10:53:11.650: I/jPCT-AE(8385): Loaded etc1_0_65162400.tex from cache!
05-13 10:53:11.650: I/jPCT-AE(8385): ...done in 1/0ms
05-13 10:53:11.650: I/jPCT-AE(8385): Creating texture buffer of size 256
05-13 10:53:11.650: I/jPCT-AE(8385): Compressing texture (16*16) to ETC1...
05-13 10:53:11.650: I/jPCT-AE(8385): Loaded etc1_1_4490357.tex from cache!
05-13 10:53:11.650: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.650: I/jPCT-AE(8385): Creating texture buffer of size 64
05-13 10:53:11.650: I/jPCT-AE(8385): Compressing texture (8*8) to ETC1...
05-13 10:53:11.650: I/jPCT-AE(8385): Loaded etc1_2_385623.tex from cache!
05-13 10:53:11.650: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.650: I/jPCT-AE(8385): Creating texture buffer of size 16
05-13 10:53:11.650: I/jPCT-AE(8385): Compressing texture (4*4) to ETC1...
05-13 10:53:11.650: I/jPCT-AE(8385): Loaded etc1_3_41594.tex from cache!
05-13 10:53:11.650: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.650: I/jPCT-AE(8385): Creating texture buffer of size 4
05-13 10:53:11.650: I/jPCT-AE(8385): Compressing texture (2*2) to ETC1...
05-13 10:53:11.650: I/jPCT-AE(8385): Loaded etc1_4_9999.tex from cache!
05-13 10:53:11.650: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.650: I/jPCT-AE(8385): Creating texture buffer of size 1
05-13 10:53:11.650: I/jPCT-AE(8385): Compressing texture (1*1) to ETC1...
05-13 10:53:11.650: I/jPCT-AE(8385): Loaded etc1_5_9349.tex from cache!
05-13 10:53:11.650: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.650: I/jPCT-AE(8385): Mipmaps generated by the CPU in 4ms
05-13 10:53:11.650: I/jPCT-AE(8385): New texture uploaded: com.threed.jpct.Texture@42d1c650 in thread Thread[GLThread 614,5,main]
05-13 10:53:11.670: D/dalvikvm(8385): GC_FOR_ALLOC freed 6590K, 46% free 22242K/41088K, paused 13ms, total 13ms
05-13 10:53:11.685: D/dalvikvm(8385): GC_FOR_ALLOC freed 1K, 44% free 23265K/41088K, paused 13ms, total 13ms
05-13 10:53:11.690: I/jPCT-AE(8385): Retrieved texture data from disk!
05-13 10:53:11.690: I/jPCT-AE(8385): Allocating native memory for 512*512 texture(true/true/false/false/): 1048576 bytes!
05-13 10:53:11.690: I/jPCT-AE(8385): Creating texture buffer of size 262144
05-13 10:53:11.705: D/dalvikvm(8385): GC_FOR_ALLOC freed 2050K, 44% free 23263K/41088K, paused 13ms, total 13ms
05-13 10:53:11.710: I/jPCT-AE(8385): New texture's id is: 840012
05-13 10:53:11.715: I/jPCT-AE(8385): New texture uploaded: com.threed.jpct.Texture@42b11bd8 in thread Thread[GLThread 614,5,main]
05-13 10:53:11.715: I/jPCT-AE(8385): Retrieved texture data from disk!
05-13 10:53:11.715: I/jPCT-AE(8385): Allocating native memory for 256*256 texture(true/false/false/false/): 131072 bytes!
05-13 10:53:11.715: I/jPCT-AE(8385): Creating texture buffer of size 32768
05-13 10:53:11.720: I/jPCT-AE(8385): New texture's id is: 910013
05-13 10:53:11.720: I/jPCT-AE(8385): Creating texture buffer of size 8192
05-13 10:53:11.720: I/jPCT-AE(8385): Creating texture buffer of size 2048
05-13 10:53:11.720: I/jPCT-AE(8385): Creating texture buffer of size 512
05-13 10:53:11.720: I/jPCT-AE(8385): Creating texture buffer of size 128
05-13 10:53:11.720: I/jPCT-AE(8385): Creating texture buffer of size 32
05-13 10:53:11.720: I/jPCT-AE(8385): Creating texture buffer of size 8
05-13 10:53:11.720: I/jPCT-AE(8385): Creating texture buffer of size 2
05-13 10:53:11.720: I/jPCT-AE(8385): Creating texture buffer of size 1
05-13 10:53:11.720: I/jPCT-AE(8385): Mipmaps generated by the CPU in 3ms
05-13 10:53:11.720: I/jPCT-AE(8385): New texture uploaded: com.threed.jpct.Texture@42c79940 in thread Thread[GLThread 614,5,main]
05-13 10:53:11.735: I/jPCT-AE(8385): Retrieved texture data from disk!
05-13 10:53:11.735: I/jPCT-AE(8385): Allocating native memory for 512*512 texture(true/true/false/false/): 1048576 bytes!
05-13 10:53:11.735: I/jPCT-AE(8385): Creating texture buffer of size 262144
05-13 10:53:11.745: D/dalvikvm(8385): GC_FOR_ALLOC freed 6244K, 44% free 23263K/41088K, paused 12ms, total 12ms
05-13 10:53:11.755: I/jPCT-AE(8385): New texture's id is: 980014
05-13 10:53:11.755: I/jPCT-AE(8385): Compressing texture (512*512) to ETC1...
05-13 10:53:11.755: I/jPCT-AE(8385): Loaded etc1_0_4123680233392.tex from cache!
05-13 10:53:11.755: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.755: I/jPCT-AE(8385): Creating texture buffer of size 65536
05-13 10:53:11.760: I/jPCT-AE(8385): Compressing texture (256*256) to ETC1...
05-13 10:53:11.760: I/jPCT-AE(8385): Loaded etc1_1_257824698597.tex from cache!
05-13 10:53:11.760: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.760: I/jPCT-AE(8385): Creating texture buffer of size 16384
05-13 10:53:11.760: I/jPCT-AE(8385): Compressing texture (128*128) to ETC1...
05-13 10:53:11.760: I/jPCT-AE(8385): Loaded etc1_2_16137527726.tex from cache!
05-13 10:53:11.760: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.760: I/jPCT-AE(8385): Creating texture buffer of size 4096
05-13 10:53:11.765: I/jPCT-AE(8385): Compressing texture (64*64) to ETC1...
05-13 10:53:11.765: I/jPCT-AE(8385): Loaded etc1_3_1014408642.tex from cache!
05-13 10:53:11.765: I/jPCT-AE(8385): ...done in 2/1ms
05-13 10:53:11.765: I/jPCT-AE(8385): Creating texture buffer of size 1024
05-13 10:53:11.765: I/jPCT-AE(8385): Compressing texture (32*32) to ETC1...
05-13 10:53:11.765: I/jPCT-AE(8385): Loaded etc1_4_64852940.tex from cache!
05-13 10:53:11.765: I/jPCT-AE(8385): ...done in 1/0ms
05-13 10:53:11.765: I/jPCT-AE(8385): Creating texture buffer of size 256
05-13 10:53:11.765: I/jPCT-AE(8385): Compressing texture (16*16) to ETC1...
05-13 10:53:11.765: I/jPCT-AE(8385): Loaded etc1_5_4412396.tex from cache!
05-13 10:53:11.765: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.770: I/jPCT-AE(8385): Creating texture buffer of size 64
05-13 10:53:11.770: I/jPCT-AE(8385): Compressing texture (8*8) to ETC1...
05-13 10:53:11.770: I/jPCT-AE(8385): Loaded etc1_6_371622.tex from cache!
05-13 10:53:11.770: I/jPCT-AE(8385): ...done in 2/1ms
05-13 10:53:11.770: I/jPCT-AE(8385): Creating texture buffer of size 16
05-13 10:53:11.770: I/jPCT-AE(8385): Compressing texture (4*4) to ETC1...
05-13 10:53:11.770: I/jPCT-AE(8385): Loaded etc1_7_44928.tex from cache!
05-13 10:53:11.770: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.770: I/jPCT-AE(8385): Creating texture buffer of size 4
05-13 10:53:11.770: I/jPCT-AE(8385): Compressing texture (2*2) to ETC1...
05-13 10:53:11.770: I/jPCT-AE(8385): Loaded etc1_8_16789.tex from cache!
05-13 10:53:11.770: I/jPCT-AE(8385): ...done in 1/0ms
05-13 10:53:11.770: I/jPCT-AE(8385): Creating texture buffer of size 1
05-13 10:53:11.770: I/jPCT-AE(8385): Compressing texture (1*1) to ETC1...
05-13 10:53:11.775: I/jPCT-AE(8385): Loaded etc1_9_16473.tex from cache!
05-13 10:53:11.775: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.775: I/jPCT-AE(8385): Mipmaps generated by the CPU in 20ms
05-13 10:53:11.775: I/jPCT-AE(8385): New texture uploaded: com.threed.jpct.Texture@42a73c68 in thread Thread[GLThread 614,5,main]
05-13 10:53:11.785: D/dalvikvm(8385): GC_FOR_ALLOC freed 4153K, 49% free 21218K/41088K, paused 12ms, total 12ms
05-13 10:53:11.790: I/jPCT-AE(8385): Retrieved texture data from disk!
05-13 10:53:11.790: I/jPCT-AE(8385): Allocating native memory for 128*128 texture(true/true/false/false/): 65536 bytes!
05-13 10:53:11.790: I/jPCT-AE(8385): Creating texture buffer of size 16384
05-13 10:53:11.790: I/jPCT-AE(8385): New texture's id is: 1050015
05-13 10:53:11.790: I/jPCT-AE(8385): Compressing texture (128*128) to ETC1...
05-13 10:53:11.790: I/jPCT-AE(8385): Loaded etc1_0_16138450227.tex from cache!
05-13 10:53:11.790: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.790: I/jPCT-AE(8385): Creating texture buffer of size 4096
05-13 10:53:11.790: I/jPCT-AE(8385): Compressing texture (64*64) to ETC1...
05-13 10:53:11.790: I/jPCT-AE(8385): Loaded etc1_1_1014589635.tex from cache!
05-13 10:53:11.790: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.790: I/jPCT-AE(8385): Creating texture buffer of size 1024
05-13 10:53:11.790: I/jPCT-AE(8385): Compressing texture (32*32) to ETC1...
05-13 10:53:11.790: I/jPCT-AE(8385): Loaded etc1_2_64894411.tex from cache!
05-13 10:53:11.790: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.790: I/jPCT-AE(8385): Creating texture buffer of size 256
05-13 10:53:11.790: I/jPCT-AE(8385): Compressing texture (16*16) to ETC1...
05-13 10:53:11.790: I/jPCT-AE(8385): Loaded etc1_3_4419254.tex from cache!
05-13 10:53:11.790: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.795: I/jPCT-AE(8385): Creating texture buffer of size 64
05-13 10:53:11.795: I/jPCT-AE(8385): Compressing texture (8*8) to ETC1...
05-13 10:53:11.795: I/jPCT-AE(8385): Loaded etc1_4_369049.tex from cache!
05-13 10:53:11.795: I/jPCT-AE(8385): ...done in 1/0ms
05-13 10:53:11.795: I/jPCT-AE(8385): Creating texture buffer of size 16
05-13 10:53:11.795: I/jPCT-AE(8385): Compressing texture (4*4) to ETC1...
05-13 10:53:11.795: I/jPCT-AE(8385): Loaded etc1_5_40814.tex from cache!
05-13 10:53:11.795: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.795: I/jPCT-AE(8385): Creating texture buffer of size 4
05-13 10:53:11.795: I/jPCT-AE(8385): Compressing texture (2*2) to ETC1...
05-13 10:53:11.795: I/jPCT-AE(8385): Loaded etc1_6_12849.tex from cache!
05-13 10:53:11.795: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.795: I/jPCT-AE(8385): Creating texture buffer of size 1
05-13 10:53:11.795: I/jPCT-AE(8385): Compressing texture (1*1) to ETC1...
05-13 10:53:11.795: I/jPCT-AE(8385): Loaded etc1_7_12911.tex from cache!
05-13 10:53:11.795: I/jPCT-AE(8385): ...done in 1/0ms
05-13 10:53:11.795: I/jPCT-AE(8385): Mipmaps generated by the CPU in 6ms
05-13 10:53:11.795: I/jPCT-AE(8385): New texture uploaded: com.threed.jpct.Texture@42c79be8 in thread Thread[GLThread 614,5,main]
05-13 10:53:11.795: I/jPCT-AE(8385): Retrieved texture data from disk!
05-13 10:53:11.795: I/jPCT-AE(8385): Allocating native memory for 128*128 texture(true/true/false/false/): 65536 bytes!
05-13 10:53:11.795: I/jPCT-AE(8385): Creating texture buffer of size 16384
05-13 10:53:11.795: I/jPCT-AE(8385): New texture's id is: 1120016
05-13 10:53:11.800: I/jPCT-AE(8385): Compressing texture (128*128) to ETC1...
05-13 10:53:11.800: I/jPCT-AE(8385): Loaded etc1_0_16140850649.tex from cache!
05-13 10:53:11.800: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.800: I/jPCT-AE(8385): Creating texture buffer of size 4096
05-13 10:53:11.800: I/jPCT-AE(8385): Compressing texture (64*64) to ETC1...
05-13 10:53:11.800: I/jPCT-AE(8385): Loaded etc1_1_1015320195.tex from cache!
05-13 10:53:11.800: I/jPCT-AE(8385): ...done in 1/0ms
05-13 10:53:11.800: I/jPCT-AE(8385): Creating texture buffer of size 1024
05-13 10:53:11.800: I/jPCT-AE(8385): Compressing texture (32*32) to ETC1...
05-13 10:53:11.800: I/jPCT-AE(8385): Loaded etc1_2_65092820.tex from cache!
05-13 10:53:11.800: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.800: I/jPCT-AE(8385): Creating texture buffer of size 256
05-13 10:53:11.800: I/jPCT-AE(8385): Compressing texture (16*16) to ETC1...
05-13 10:53:11.800: I/jPCT-AE(8385): Loaded etc1_3_4468644.tex from cache!
05-13 10:53:11.800: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.800: I/jPCT-AE(8385): Creating texture buffer of size 64
05-13 10:53:11.800: I/jPCT-AE(8385): Compressing texture (8*8) to ETC1...
05-13 10:53:11.800: I/jPCT-AE(8385): Loaded etc1_4_381684.tex from cache!
05-13 10:53:11.800: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.800: I/jPCT-AE(8385): Creating texture buffer of size 16
05-13 10:53:11.800: I/jPCT-AE(8385): Compressing texture (4*4) to ETC1...
05-13 10:53:11.800: I/jPCT-AE(8385): Loaded etc1_5_43800.tex from cache!
05-13 10:53:11.800: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.800: I/jPCT-AE(8385): Creating texture buffer of size 4
05-13 10:53:11.800: I/jPCT-AE(8385): Compressing texture (2*2) to ETC1...
05-13 10:53:11.805: I/jPCT-AE(8385): Loaded etc1_6_13535.tex from cache!
05-13 10:53:11.805: I/jPCT-AE(8385): ...done in 1/1ms
05-13 10:53:11.805: I/jPCT-AE(8385): Creating texture buffer of size 1
05-13 10:53:11.805: I/jPCT-AE(8385): Compressing texture (1*1) to ETC1...
05-13 10:53:11.805: I/jPCT-AE(8385): Loaded etc1_7_12911.tex from cache!
05-13 10:53:11.805: I/jPCT-AE(8385): ...done in 0/0ms
05-13 10:53:11.805: I/jPCT-AE(8385): Mipmaps generated by the CPU in 6ms
05-13 10:53:11.805: I/jPCT-AE(8385): New texture uploaded: com.threed.jpct.Texture@42b0ef30 in thread Thread[GLThread 614,5,main]
05-13 10:53:11.805: I/jPCT-AE(8385): Pre-warming done!
05-13 10:53:11.805: I/jPCT-AE(8385): Recompiling shader because of context change!
05-13 10:53:11.805: I/jPCT-AE(8385): Compiling shader program!
05-13 10:53:11.900: I/jPCT-AE(8385): Handles of 1890027: 4/44/5
05-13 10:53:11.900: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:11.900: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:11.905: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:11.905: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:11.905: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:11.905: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:11.915: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:11.915: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:11.915: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:11.915: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:11.920: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:11.920: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:11.920: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:11.920: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:11.920: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:11.920: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:11.925: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:11.925: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:11.925: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:11.925: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:11.925: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:11.925: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:11.930: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:11.930: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:11.930: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:11.930: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:11.930: I/jPCT-AE(8385): Recompiling shader because of context change!
05-13 10:53:11.930: I/jPCT-AE(8385): Compiling shader program!
05-13 10:53:12.080: I/jPCT-AE(8385): Handles of 2100030: 4/44/5
05-13 10:53:12.080: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:12.080: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:12.085: I/jPCT-AE(8385): Recompiling shader because of context change!
05-13 10:53:12.085: I/jPCT-AE(8385): Compiling shader program!
05-13 10:53:12.090: I/jPCT-AE(8385): Handles of 2310033: 4/44/5
05-13 10:53:12.090: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:12.090: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:12.090: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:12.090: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:12.090: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:12.090: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:12.090: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:12.090: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:12.090: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:12.090: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:12.090: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:12.090: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:12.100: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:12.100: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:12.100: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:12.100: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:12.100: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:12.100: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:12.100: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:12.100: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:12.100: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:12.100: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:12.100: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:12.100: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:12.105: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:12.105: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:12.105: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:12.105: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:12.105: I/jPCT-AE(8385): Recompiling shader because of context change!
05-13 10:53:12.105: I/jPCT-AE(8385): Compiling shader program!
05-13 10:53:12.195: I/jPCT-AE(8385): Handles of 2520036: 5/6/-1
05-13 10:53:12.195: I/jPCT-AE(8385): OpenGL context has changed(2)...recovering for renderer 2/1!
05-13 10:53:12.195: I/jPCT-AE(8385): Creating buffers...
05-13 10:53:12.200: V/Kision(8385): com.test.deepocean.MainActivity$1@42b03278: 39fps
05-13 10:53:13.235: V/Kision(8385): com.test.deepocean.MainActivity$1@42b03278: 11fps
05-13 10:53:14.285: V/Kision(8385): com.test.deepocean.MainActivity$1@42b03278: 8fps
05-13 10:53:15.525: V/Kision(8385): com.test.deepocean.MainActivity$1@42b03278: 7fps
05-13 10:53:16.545: V/Kision(8385): com.test.deepocean.MainActivity$1@42b03278: 6fps
05-13 10:53:17.565: V/Kision(8385): com.test.deepocean.MainActivity$1@42b03278: 6fps
05-13 10:53:18.590: V/Kision(8385): com.test.deepocean.MainActivity$1@42b03278: 5fps
05-13 10:53:23.745: V/Kision(8385): com.test.deepocean.MainActivity$1@42b03278: 1fps
05-13 10:53:28.830: V/Kision(8385): com.test.deepocean.MainActivity$1@42b03278: 1fps


In logging the fps, I also print out the Renderer instance to see if mulitple renderer is drawing at the same time. 1fps means it's flickering.

BTW, there was once I got this error when the phone froze:
05-13 10:39:27.426: E/IMGSRV(6595): :0: WaitForRender: Timeout
05-13 10:39:27.426: E/IMGSRV(6595): :0: HW operation timeout occurred.
05-13 10:39:27.426: E/IMGSRV(6595): :0: MapperLogSyncObjects: Dumping buffered log messages..
05-13 10:39:27.426: E/IMGSRV(6595): :0: MapperLogSyncObjects: Dumping all active sync objects..
05-13 10:39:27.426: E/IMGSRV(6595): :0: ID=508, 0xP...FHWR=0x00000b00, WOP/WOC=0x9/0x9, ROP/ROC=0x6/0x5, ROP2/ROC2=0x0/0x0, WOC DevVA=0xef008054, ROC DevVA=0xef00805c, ROC2 DevVA=0xef008064
05-13 10:39:27.426: E/IMGSRV(6595): :0: ID=507, 0xP...FHWR=0x00000b00, WOP/WOC=0x9/0x9, ROP/ROC=0x6/0x5, ROP2/ROC2=0x0/0x0, WOC DevVA=0xef009554, ROC DevVA=0xef00955c, ROC2 DevVA=0xef009564
05-13 10:39:27.426: E/IMGSRV(6595): :0: ID=506, 0xP...FHWR=0x00000b00, WOP/WOC=0xa/0x9, ROP/ROC=0x6/0x5, ROP2/ROC2=0x0/0x0, WOC DevVA=0xef00802c, ROC DevVA=0xef008034, ROC2 DevVA=0xef00803c
05-13 10:39:27.426: E/IMGSRV(6595): :0: ID=505, 0xP...FHWR=0x00000b00, WOP/WOC=0xa/0x9, ROP/ROC=0x6/0x5, ROP2/ROC2=0x0/0x0, WOC DevVA=0xef007964, ROC DevVA=0xef00796c, ROC2 DevVA=0xef007974
05-13 10:39:27.426: E/IMGSRV(6595): :0: ID=492, 0xP...FHWR=0x00000b00, WOP/WOC=0x1/0x1, ROP/ROC=0x2e/0x2a, ROP2/ROC2=0x0/0x0, WOC DevVA=0xef006a7c, ROC DevVA=0xef006a84, ROC2 DevVA=0xef006a8c
05-13 10:39:27.426: E/IMGSRV(6595): :0: ID=487, 0xP...FHWR=0x00000b00, WOP/WOC=0x1/0x1, ROP/ROC=0x26/0x26, ROP2/ROC2=0x0/0x0, WOC DevVA=0xef0096bc, ROC DevVA=0xef0096c4, ROC2 DevVA=0xef0096cc
05-13 10:39:27.426: E/IMGSRV(6595): :0: ID=486, 0xP...FHWR=0x00000b00, WOP/WOC=0x1/0x1, ROP/ROC=0x1/0x1, ROP2/ROC2=0x0/0x0, WOC DevVA=0xef009694, ROC DevVA=0xef00969c, ROC2 DevVA=0xef0096a4
05-13 10:39:27.426: E/IMGSRV(6595): :0: ID=8, 0xP...FHWR=0x00000100, WOP/WOC=0x0/0x0, ROP/ROC=0x0/0x0, ROP2/ROC2=0x0/0x0, WOC DevVA=0xef0014b4, ROC DevVA=0xef0014bc, ROC2 DevVA=0xef0014c4
05-13 10:39:27.426: E/IMGSRV(6595): :0: ID=484, 0xP...FHWR=0x00000b00, WOP/WOC=0x1/0x1, ROP/ROC=0x0/0x0, ROP2/ROC2=0x0/0x0, WOC DevVA=0xef0097ac, ROC DevVA=0xef0097b4, ROC2 DevVA=0xef0097bc
05-13 10:39:32.436: E/IMGSRV(6595): :0: KEGL_SGXDestroyRenderSurface: Timeout failed on waiting for previous render op
05-13 10:39:32.436: E/IMGSRV(6595): :0: FreePDSFragBuffers: PDS fragment buffer for render surface still in use
05-13 10:39:35.481: E/IMGSRV(6595): :0: Failed to flush HW render context (24)
05-13 10:39:35.481: E/IMGSRV(6595): :0: KEGLDestroyRenderSurface: Couldn't remove render target
05-13 10:39:35.686: D/dalvikvm(6595): [SWE] ### S.LSI JIT optimization list BEGIN ###
05-13 10:39:35.686: D/dalvikvm(6595): [SWE] ### S.LSI JIT optimization list END ###
05-13 10:39:35.686: A/libc(6595): Fatal signal 11 (SIGSEGV) at 0x00000180 (code=1), thread 6644 (Thread-1400)


I checked again using Opengl es tracer, and I found out context0 did some gl operations, then context1 did some, by taking turns (the flicker has not happen at this point), but this rarely happens.

EgonOlsen

I've no idea...can you create a test case and/or post your onDrawFrame()-method's code?

kkl

My onDrawFrame is something like this


long updateTime = 0, renderTime = 0, drawTime = 0, displayTime = 0, tempStart, tempEnd;
frame.clear(BACK_COLOR);
tempStart = System.currentTimeMillis();
update();
tempEnd = System.currentTimeMillis();
updateTime = tempEnd - tempStart;

tempStart = System.currentTimeMillis();
world.renderScene(frame);
tempEnd = System.currentTimeMillis();
renderTime = tempEnd - tempStart;

tempStart = System.currentTimeMillis();
world.draw(frame);
tempEnd = System.currentTimeMillis();
drawTime = tempEnd - tempStart;

tempStart = System.currentTimeMillis();
frame.display();
tempEnd = System.currentTimeMillis();
displayTime = tempEnd - tempStart;


endTime = System.currentTimeMillis();
long dt = endTime - startTime;

if (dt < wantedSleepTime)
try {
Thread.sleep(wantedSleepTime - (int)dt);
} catch (InterruptedException e) {
e.printStackTrace();
}
startTime = System.currentTimeMillis();

if (System.currentTimeMillis() - time >= 1000) {
LogUtils.log(MainRenderer.this + ": "+fps + "fps");
// LogUtils.log("Sleep " + (wantedSleepTime - (int)dt));
// LogUtils.log("Update: " + updateTime + ", Render: " + renderTime + ", Draw: " + drawTime + ", display:" + displayTime);
fps = 0;
time = System.currentTimeMillis();
}
fps++;


The update() is the one updating animations. The rest is almost the same with JPCT example, with addition thread sleep.

I tried to create a test case but I can't replicate the error. I'm still trying though..

EgonOlsen

Have you checked the values in the sleep call?


wantedSleepTime - (int)dt


Maybe you are sleeping for too long by some accident?

kkl

Yes. It prints out less than 20. Before I implemented the sleep, the screen flicker was already there. Just that I leave it for quite some time while I was developing other stuff. I thought the flicker just happens in normal app and LWP should be ok, but things didn't go well.

EgonOlsen

I would limit it to >=0 anyway, because it might become <0 and that would cause the onDrawFrame method to blow.
Are you by any chance swallowing some exceptions in onDrawFrame?

kkl

QuoteAre you by any chance swallowing some exceptions in onDrawFrame?
No, swallowing exception can affect performance and I don't do that. Once there is exception, it would crash the app directly.

BTW, I removed all synchronizing lock and it seems to have no freezing now. I used that lock previously to control engine onCreate and renderer onDrawFrame so that both don't call at the same time as it causes flickers when switching from renderer to another. After removing the lock, it still stutters in the first few frames occasionally, but it returns to normal after that. I'll observe that closely and see if it still causes the problem. Thanks alot for giving such great support. Appreciate it.