www.jpct.net

jPCT-AE - a 3d engine for Android => Support => Topic started by: kkl on May 28, 2013, 04:45:58 am

Title: Strange looking preference activity in livewallpaper
Post by: kkl on May 28, 2013, 04:45:58 am: Hi,

Does anyone have the strange looking preference activity in android before? The fonts in preference activity becomes square after some settings have been made there.

Step to reproduce:
1. Load texture and add objects to world
2. In preference activity, if the feature is unchecked by user, unload texture immediately and remove objects from world.
3. Go back to livewallpaper preview.
4. Goto the preference activity again. It shows square font (font is in english, no other language), and no errors from JPCT-AE log.

However, if I don't unload the texture and only remove objects from world, it doesn't cause the error.

[attachment deleted by admin]
Title: Re: Strange looking preference activity in livewallpaper
Post by: EgonOlsen on May 28, 2013, 11:18:11 am: Looks like as if the textures of the font get unloaded, which can only be caused if the unloading happens in the wrong gl context. Honestly, i don't see how this should be possible. I assume that Config.unloadImmediately has been set to true? Does this happen on all devices? It might be a driver bug as well...
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on May 28, 2013, 05:21:36 pm: I never expect that happen too. Yes, Config.unloadImmediately is set to true. I tried it on S2, nexus 4 and nexus 7, all have the same weird looking preference activity after the steps are reproduced (nexus 4 and nexus 7 show broken texture at the preference activity group titles respectively). Judging from what you said, i started to think it can be possible as I share the texture for both livewallpapers from home screen and preview. It happens when I disable a feature from preview, and the preview tries to unload the texture from livewallpaper home screen; different gl context.

Egon, what would you suggest? Is it possible to unload texture with finding back the correct gl context? (I tried dispose everything when onPause() is called and reload all textures and objects during onResume(), but it takes a long time to reload everything back which causes my livewallpaper a big lag at the beginning)
Title: Re: Strange looking preference activity in livewallpaper
Post by: EgonOlsen on May 28, 2013, 08:16:43 pm: If you are unloading the texture in anything but the onDraw()-method, it happens in another thread and nobody knows which context is active then. There's nothing i can do about it and the only solution is not to do it. Why are you unloading the textures anyway? The native resources that they are using should be freed once the context is lost.
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on May 29, 2013, 04:15:22 am: I have a feature in which it changes texture based on user's preference. The textures are huge and it may cause memory error if I load all of them. So, I load the texture that is needed and unload the one that is not needed.
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on May 29, 2013, 10:57:49 am: Hi Egon,

I tried by just having livewallpaper preview without setting it to the phone, and unloading texture still causes error. I checked from jPCT-ae log, it says opengl context has changed.

Code: [Select]
05-29 16:50:15.218: I/jPCT-AE(6647): Visibility lists disposed! 05-29 16:50:15.218: I/jPCT-AE(6647): All texture data unloaded from gpu! 05-29 16:50:15.218: I/jPCT-AE(6647): Disposing VBOs! 05-29 16:50:15.223: I/jPCT-AE(6647): Renderer disposed! 05-29 16:50:15.228: I/jPCT-AE(6647): OpenGL vendor: ARM 05-29 16:50:15.228: I/jPCT-AE(6647): OpenGL renderer: Mali-400 MP 05-29 16:50:15.228: I/jPCT-AE(6647): OpenGL version: OpenGL ES-CM 1.1 05-29 16:50:15.228: I/jPCT-AE(6647): OpenGL renderer initialized (using 2 texture stages) 05-29 16:50:15.228: I/jPCT-AE(6647): OpenGL context has changed(2)...recovering for renderer 14/13!
It also says all textures unloaded from GPU while I din't flush the TextureManger explicitly. May I know what is happening there and why the gl context changed when it resumes to the same livewallpaper preview? (The log pops up when I goto preference activity and come back to the preview)
Title: Re: Strange looking preference activity in livewallpaper
Post by: EgonOlsen on May 29, 2013, 11:26:13 am: If you create a new framebuffer, it will consider this as a context change. If you can make sure that the context hasn't changed, don't create a new framebuffer.
Title: Re: Strange looking preference activity in livewallpaper
Post by: EgonOlsen on May 29, 2013, 11:30:52 am: Could you please set the Logger to debug and post the output after some context changes?
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on May 29, 2013, 01:59:39 pm: These are the logs in debug level after closing preference activity and resuming to preview:

Code: [Select]
05-29 19:47:42.610: I/jPCT-AE(13608): Unloaded texture: 3 05-29 19:47:42.630: I/jPCT-AE(13608): Visibility lists disposed! 05-29 19:47:42.630: I/jPCT-AE(13608): Unloaded texture: 6 05-29 19:47:42.630: I/jPCT-AE(13608): Unloaded texture: 4 05-29 19:47:42.630: I/jPCT-AE(13608): Unloaded texture: 2 05-29 19:47:42.630: I/jPCT-AE(13608): Unloaded texture: 1 05-29 19:47:42.630: I/jPCT-AE(13608): Unloaded texture: 5 05-29 19:47:42.630: I/jPCT-AE(13608): All texture data unloaded from gpu! 05-29 19:47:42.630: I/jPCT-AE(13608): Disposing VBOs! 05-29 19:47:42.640: I/jPCT-AE(13608): Renderer disposed! 05-29 19:47:42.640: I/jPCT-AE(13608): GLRenderer disposed with id 1 on Thread[GLThread 55676,5,main] 05-29 19:47:42.640: I/jPCT-AE(13608): GLRenderer created with id 2 on Thread[GLThread 55676,5,main] 05-29 19:47:42.645: I/jPCT-AE(13608): OpenGL vendor: ARM 05-29 19:47:42.645: I/jPCT-AE(13608): OpenGL renderer: Mali-400 MP 05-29 19:47:42.645: I/jPCT-AE(13608): OpenGL version: OpenGL ES-CM 1.1 05-29 19:47:42.645: I/jPCT-AE(13608): OpenGL renderer initialized (using 2 texture stages) 05-29 19:47:42.645: I/jPCT-AE(13608): Allocating native memory for 128*128 texture(true/false/false/false/): 65536 bytes! 05-29 19:47:42.650: I/jPCT-AE(13608): New texture's id is: 1 05-29 19:47:42.650: I/jPCT-AE(13608): New texture uploaded: com.threed.jpct.Texture@41f82c48 in thread Thread[GLThread 55676,5,main] 05-29 19:47:42.650: I/jPCT-AE(13608): OpenGL context has changed(2)...recovering for renderer 2/1! 05-29 19:47:42.650: I/jPCT-AE(13608): Creating buffers... 05-29 19:47:42.650: I/jPCT-AE(13608): OpenGL context has changed(2)...recovering for renderer 2/1! 05-29 19:47:42.650: I/jPCT-AE(13608): Creating buffers... 05-29 19:47:42.650: I/jPCT-AE(13608): OpenGL context has changed(2)...recovering for renderer 2/1! 05-29 19:47:42.650: I/jPCT-AE(13608): Creating buffers... 05-29 19:47:42.650: I/jPCT-AE(13608): OpenGL context has changed(2)...recovering for renderer 2/1! 05-29 19:47:42.650: I/jPCT-AE(13608): Creating buffers... 05-29 19:47:42.650: I/jPCT-AE(13608): OpenGL context has changed(2)...recovering for renderer 2/1! 05-29 19:47:42.650: I/jPCT-AE(13608): Creating buffers... 05-29 19:47:42.655: I/jPCT-AE(13608): Allocating native memory for 1024*1024 texture(true/false/false/false/): 4194304 bytes! 05-29 19:47:42.905: I/jPCT-AE(13608): VBO disposed for object 'firefly1' 05-29 19:47:42.905: I/jPCT-AE(13608): VBO disposed for object 'firefly2' 05-29 19:47:42.905: I/jPCT-AE(13608): VBO disposed for object 'firefly3' 05-29 19:47:42.905: I/jPCT-AE(13608): VBO disposed for object 'firefly4' 05-29 19:47:42.905: I/jPCT-AE(13608): VBO disposed for object 'firefly5' 05-29 19:47:42.905: I/jPCT-AE(13608): VBO disposed for object 'firefly6' 05-29 19:47:42.905: I/jPCT-AE(13608): VBO disposed for object 'firefly7' 05-29 19:47:42.905: I/jPCT-AE(13608): VBO disposed for object 'firefly8' 05-29 19:47:42.905: I/jPCT-AE(13608): VBO disposed for object 'firefly9' 05-29 19:47:42.905: I/jPCT-AE(13608): VBO disposed for object 'firefly10' 05-29 19:47:42.920: I/jPCT-AE(13608): New texture's id is: 2 05-29 19:47:42.940: I/jPCT-AE(13608): New texture uploaded: com.threed.jpct.Texture@41f82fa8 in thread Thread[GLThread 55676,5,main] 05-29 19:47:42.940: I/jPCT-AE(13608): OpenGL context has changed(2)...recovering for renderer 2/1! 05-29 19:47:42.940: I/jPCT-AE(13608): Creating buffers... 05-29 19:47:42.940: I/jPCT-AE(13608): Allocating native memory for 1024*1024 texture(true/false/false/false/): 4194304 bytes! 05-29 19:47:43.165: I/jPCT-AE(13608): New texture's id is: 4 05-29 19:47:43.175: I/jPCT-AE(13608): New texture uploaded: com.threed.jpct.Texture@41f71e68 in thread Thread[GLThread 55676,5,main] 05-29 19:47:43.175: I/jPCT-AE(13608): OpenGL context has changed(2)...recovering for renderer 2/1! 05-29 19:47:43.175: I/jPCT-AE(13608): Creating buffers... 05-29 19:47:43.175: I/jPCT-AE(13608): OpenGL context has changed(2)...recovering for renderer 2/1! 05-29 19:47:43.175: I/jPCT-AE(13608): Creating buffers... 05-29 19:47:43.175: I/jPCT-AE(13608): OpenGL context has changed(2)...recovering for renderer 2/1! 05-29 19:47:43.175: I/jPCT-AE(13608): Creating buffers... 05-29 19:47:43.175: I/jPCT-AE(13608): Allocating native memory for 64*64 texture(true/false/false/false/): 16384 bytes! 05-29 19:47:43.175: I/jPCT-AE(13608): New texture's id is: 5 05-29 19:47:43.175: I/jPCT-AE(13608): New texture uploaded: com.threed.jpct.Texture@41f76910 in thread Thread[GLThread 55676,5,main] 05-29 19:47:43.175: I/jPCT-AE(13608): OpenGL context has changed(2)...recovering for renderer 2/1! 05-29 19:47:43.175: I/jPCT-AE(13608): Creating buffers... 05-29 19:47:43.180: I/jPCT-AE(13608): OpenGL context has changed(2)...recovering for renderer 2/1! 05-29 19:47:43.180: I/jPCT-AE(13608): Creating buffers... 05-29 19:47:43.180: I/jPCT-AE(13608): OpenGL context has changed(2)...recovering for renderer 2/1! 05-29 19:47:43.180: I/jPCT-AE(13608): Creating buffers... 05-29 19:47:43.180: I/jPCT-AE(13608): OpenGL context has changed(2)...recovering for renderer 2/1! 05-29 19:47:43.180: I/jPCT-AE(13608): Creating buffers... 05-29 19:47:43.180: I/jPCT-AE(13608): OpenGL context has changed(2)...recovering for renderer 2/1! 05-29 19:47:43.180: I/jPCT-AE(13608): Creating buffers... 05-29 19:47:43.180: I/jPCT-AE(13608): OpenGL context has changed(2)...recovering for renderer 2/1! 05-29 19:47:43.180: I/jPCT-AE(13608): Creating buffers... 05-29 19:47:43.180: I/jPCT-AE(13608): OpenGL context has changed(2)...recovering for renderer 2/1! 05-29 19:47:43.180: I/jPCT-AE(13608): Creating buffers... 05-29 19:47:43.180: I/jPCT-AE(13608): Allocating native memory for 64*64 texture(true/false/false/false/): 16384 bytes! 05-29 19:47:43.185: I/jPCT-AE(13608): New texture's id is: 6 05-29 19:47:43.185: I/jPCT-AE(13608): New texture uploaded: com.threed.jpct.Texture@41f6db30 in thread Thread[GLThread 55676,5,main] 05-29 19:47:43.185: I/jPCT-AE(13608): OpenGL context has changed(2)...recovering for renderer 2/1! 05-29 19:47:43.185: I/jPCT-AE(13608): Creating buffers... 05-29 19:47:43.185: I/jPCT-AE(13608): OpenGL context has changed(2)...recovering for renderer 2/1! 05-29 19:47:43.185: I/jPCT-AE(13608): Creating buffers...
I also tried without creating the new framebuffer when context changes. The same issue is still there. Surprisingly, I do exactly the same method to other objects and textures, it works fine.
Title: Re: Strange looking preference activity in livewallpaper
Post by: EgonOlsen on May 29, 2013, 08:00:27 pm: Looks fine to me. You are obviously disposing the framebuffer and creating a new one in the same thread...when does this happen and why? I'm still not sure about what exactly you are doing...

You have a preview activity, you pause and open the preferences, you close the preferences and resume the preview activity? At which stage are you disposing the framebuffer? Before or after pausing the preview activity?
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on May 30, 2013, 04:17:04 am: I dispose the framebuffer after pausing the preview. To be exact, it's resuming the preview.

This is the flow where I dispose the framebuffer in a nutshell.

onPause() -> (Goto Preference activity) -> (Quit preference activity) -> onResume() -> onSurfaceChanged() -> (dispose framebuffer)

Does disposing the framebuffer change the gl context and affect on unloading textures?
Title: Re: Strange looking preference activity in livewallpaper
Post by: EgonOlsen on May 30, 2013, 07:16:40 am: Disposing the buffer unloads textures, but it doesn't do anything to the context. Try to dispose the framebuffer before opening the preferences, i.e. somewhere in onPause() and see what that does...
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on May 30, 2013, 12:40:43 pm: Wow.. Disposing frame buffer on onPause() fixed the problem. No more square font so far. What is exactly happening there?

The logs on onPause():
Code: [Select]
05-30 18:35:33.138: I/jPCT-AE(6570): Visibility lists disposed! 05-30 18:35:33.138: I/jPCT-AE(6570): Unloaded texture: 38 05-30 18:35:33.138: I/jPCT-AE(6570): Unloaded texture: 36 05-30 18:35:33.138: I/jPCT-AE(6570): Unloaded texture: 35 05-30 18:35:33.138: I/jPCT-AE(6570): Unloaded texture: 33 05-30 18:35:33.138: I/jPCT-AE(6570): Unloaded texture: 37 05-30 18:35:33.138: I/jPCT-AE(6570): Unloaded texture: 34 05-30 18:35:33.138: I/jPCT-AE(6570): All texture data unloaded from gpu! 05-30 18:35:33.138: I/jPCT-AE(6570): Disposing VBOs! 05-30 18:35:33.138: I/jPCT-AE(6570): Renderer disposed! 05-30 18:35:33.138: I/jPCT-AE(6570): GLRenderer disposed with id 28 on Thread[main,5,main]

The logs on onResume():
Code: [Select]
05-30 18:35:46.048: I/jPCT-AE(6570): GLRenderer created with id 29 on Thread[GLThread 57759,5,main] 05-30 18:35:46.048: I/jPCT-AE(6570): OpenGL vendor: ARM 05-30 18:35:46.053: I/jPCT-AE(6570): OpenGL renderer: Mali-400 MP 05-30 18:35:46.053: I/jPCT-AE(6570): OpenGL version: OpenGL ES-CM 1.1 05-30 18:35:46.053: I/jPCT-AE(6570): OpenGL renderer initialized (using 2 texture stages) 05-30 18:35:46.053: I/jPCT-AE(6570): Allocating native memory for 128*128 texture(true/false/false/false/): 65536 bytes! 05-30 18:35:46.053: I/jPCT-AE(6570): New texture's id is: 39 05-30 18:35:46.053: I/jPCT-AE(6570): New texture uploaded: com.threed.jpct.Texture@425b70c8 in thread Thread[GLThread 57759,5,main] 05-30 18:35:46.053: I/jPCT-AE(6570): OpenGL context has changed(2)...recovering for renderer 29/28! 05-30 18:35:46.053: I/jPCT-AE(6570): Creating buffers... 05-30 18:35:46.053: I/jPCT-AE(6570): OpenGL context has changed(2)...recovering for renderer 29/28! 05-30 18:35:46.053: I/jPCT-AE(6570): Creating buffers... 05-30 18:35:46.053: I/jPCT-AE(6570): OpenGL context has changed(2)...recovering for renderer 29/28! 05-30 18:35:46.053: I/jPCT-AE(6570): Creating buffers... 05-30 18:35:46.053: I/jPCT-AE(6570): OpenGL context has changed(2)...recovering for renderer 29/28! 05-30 18:35:46.053: I/jPCT-AE(6570): Creating buffers... 05-30 18:35:46.053: I/jPCT-AE(6570): OpenGL context has changed(2)...recovering for renderer 29/28! 05-30 18:35:46.053: I/jPCT-AE(6570): Creating buffers... 05-30 18:35:46.063: I/jPCT-AE(6570): Allocating native memory for 1024*1024 texture(true/false/false/false/): 4194304 bytes! 05-30 18:35:46.148: I/jPCT-AE(6570): VBO disposed for object 'firefly9' 05-30 18:35:46.148: I/jPCT-AE(6570): VBO disposed for object 'firefly1' 05-30 18:35:46.148: I/jPCT-AE(6570): VBO disposed for object 'firefly2' 05-30 18:35:46.148: I/jPCT-AE(6570): VBO disposed for object 'firefly3' 05-30 18:35:46.148: I/jPCT-AE(6570): VBO disposed for object 'firefly4' 05-30 18:35:46.148: I/jPCT-AE(6570): VBO disposed for object 'firefly5' 05-30 18:35:46.148: I/jPCT-AE(6570): VBO disposed for object 'firefly6' 05-30 18:35:46.148: I/jPCT-AE(6570): VBO disposed for object 'firefly7' 05-30 18:35:46.148: I/jPCT-AE(6570): VBO disposed for object 'firefly8' 05-30 18:35:46.153: I/jPCT-AE(6570): VBO disposed for object 'firefly10' 05-30 18:35:46.333: I/jPCT-AE(6570): New texture's id is: 40 05-30 18:35:46.378: I/jPCT-AE(6570): New texture uploaded: com.threed.jpct.Texture@4271bb30 in thread Thread[GLThread 57759,5,main] 05-30 18:35:46.378: I/jPCT-AE(6570): OpenGL context has changed(2)...recovering for renderer 29/28! 05-30 18:35:46.378: I/jPCT-AE(6570): Creating buffers... 05-30 18:35:46.378: I/jPCT-AE(6570): Allocating native memory for 1024*1024 texture(true/false/false/false/): 4194304 bytes! 05-30 18:35:46.543: I/jPCT-AE(6570): New texture's id is: 41 05-30 18:35:46.583: I/jPCT-AE(6570): New texture uploaded: com.threed.jpct.Texture@42720e70 in thread Thread[GLThread 57759,5,main] 05-30 18:35:46.583: I/jPCT-AE(6570): OpenGL context has changed(2)...recovering for renderer 29/28! 05-30 18:35:46.583: I/jPCT-AE(6570): Creating buffers... 05-30 18:35:46.583: I/jPCT-AE(6570): OpenGL context has changed(2)...recovering for renderer 29/28! 05-30 18:35:46.583: I/jPCT-AE(6570): Creating buffers... 05-30 18:35:46.583: I/jPCT-AE(6570): OpenGL context has changed(2)...recovering for renderer 29/28! 05-30 18:35:46.583: I/jPCT-AE(6570): Creating buffers... 05-30 18:35:46.583: I/jPCT-AE(6570): Allocating native memory for 64*64 texture(true/false/false/false/): 16384 bytes! 05-30 18:35:46.583: I/jPCT-AE(6570): New texture's id is: 42 05-30 18:35:46.583: I/jPCT-AE(6570): New texture uploaded: com.threed.jpct.Texture@420e63c0 in thread Thread[GLThread 57759,5,main] 05-30 18:35:46.583: I/jPCT-AE(6570): OpenGL context has changed(2)...recovering for renderer 29/28! 05-30 18:35:46.583: I/jPCT-AE(6570): Creating buffers... 05-30 18:35:46.583: I/jPCT-AE(6570): OpenGL context has changed(2)...recovering for renderer 29/28! 05-30 18:35:46.583: I/jPCT-AE(6570): Creating buffers... 05-30 18:35:46.583: I/jPCT-AE(6570): OpenGL context has changed(2)...recovering for renderer 29/28! 05-30 18:35:46.583: I/jPCT-AE(6570): Creating buffers... 05-30 18:35:46.583: I/jPCT-AE(6570): OpenGL context has changed(2)...recovering for renderer 29/28! 05-30 18:35:46.583: I/jPCT-AE(6570): Creating buffers... 05-30 18:35:46.588: I/jPCT-AE(6570): OpenGL context has changed(2)...recovering for renderer 29/28! 05-30 18:35:46.588: I/jPCT-AE(6570): Creating buffers... 05-30 18:35:46.588: I/jPCT-AE(6570): OpenGL context has changed(2)...recovering for renderer 29/28! 05-30 18:35:46.588: I/jPCT-AE(6570): Creating buffers... 05-30 18:35:46.588: I/jPCT-AE(6570): OpenGL context has changed(2)...recovering for renderer 29/28! 05-30 18:35:46.588: I/jPCT-AE(6570): Creating buffers... 05-30 18:35:46.588: I/jPCT-AE(6570): Allocating native memory for 64*64 texture(true/false/false/false/): 16384 bytes! 05-30 18:35:46.588: I/jPCT-AE(6570): New texture's id is: 43 05-30 18:35:46.588: I/jPCT-AE(6570): New texture uploaded: com.threed.jpct.Texture@421379c8 in thread Thread[GLThread 57759,5,main] 05-30 18:35:46.588: I/jPCT-AE(6570): OpenGL context has changed(2)...recovering for renderer 29/28! 05-30 18:35:46.588: I/jPCT-AE(6570): Creating buffers... 05-30 18:35:46.588: I/jPCT-AE(6570): OpenGL context has changed(2)...recovering for renderer 29/28! 05-30 18:35:46.588: I/jPCT-AE(6570): Creating buffers...
Title: Re: Strange looking preference activity in livewallpaper
Post by: EgonOlsen on May 30, 2013, 01:57:01 pm: I'm not 100% sure. Textures in a context are identified by a driver generated id. Once an id becomes freed or invalid because of a context loss, the driver is free to give it to another texture (or other data on the gpu). If you call dispose() after the resume, you are freeing textures bound to ids that actually belong to the preferences dialog now. I'll update the documentation to dispose() to make clear that it should be called BEFORE the current context gets out of scope.
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on May 31, 2013, 06:51:42 am: If I don't dispose the framebuffer, and use the old framebuffer after onResume(), the problem seems to be the same. Is there any way to update the driver id without disposing frame buffer? Coz disposing the frame buffer causes a slight lag on onResume().
Title: Re: Strange looking preference activity in livewallpaper
Post by: EgonOlsen on May 31, 2013, 03:21:36 pm: No, because the FrameBuffer is bound to the context. Not the new FrameBuffer causes the delay, but the context change.
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on June 01, 2013, 11:24:06 am: Ok. I've tested out the new method, it seemed like there was memory leak. The memory leaks in the actual RAM, not in VM RAM though. After a few times of onResume(), the available RAM declined from 260MB to 60MB. However, if I use the old method (frame buffer is disposed at onResume()), the memory stays constant. It seems like the textures are left in GPU after the context change and the textures are no longer being linked with the correct driver generated id. What should I do?
Title: Re: Strange looking preference activity in livewallpaper
Post by: EgonOlsen on June 01, 2013, 02:38:43 pm: No idea why this should happen...the log output looks fine. Honestly, this wallpaper stuff is driving me nuts... :) Maybe it's best to take one step back...does the GL instance actually changes between onPause and onSurfaceChanged? If not, there's no need to create a new buffer or do dispose anything. If all you want is to change a texture based on the preferences, there's no need to remove and upload all the textures either. Just use replaceTexture in the TextureManager to replace the changed texture.
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on June 01, 2013, 03:45:03 pm: It really does suck with this wallpaper. I've been debugging for few days since the problem occurred too.

I think gl context doesn't change between onPause and onSurfaceChanged. Here's the log:

I logged all states. (This is still the one with frame buffer disposed at onResume(). )
Code: [Select]
06-01 21:19:50.421: I/jPCT-AE(6423): Engine onPause(): 06-01 21:19:52.111: I/jPCT-AE(6423): Engine onResume(): 06-01 21:19:52.121: I/jPCT-AE(6423): onSurfaceChanged! 06-01 21:19:52.121: I/jPCT-AE(6423): Visibility lists disposed! 06-01 21:19:52.121: I/jPCT-AE(6423): Unloaded texture: 6 06-01 21:19:52.121: I/jPCT-AE(6423): Unloaded texture: 5 06-01 21:19:52.121: I/jPCT-AE(6423): Unloaded texture: 2 06-01 21:19:52.121: I/jPCT-AE(6423): Unloaded texture: 3 06-01 21:19:52.121: I/jPCT-AE(6423): Unloaded texture: 1 06-01 21:19:52.121: I/jPCT-AE(6423): Unloaded texture: 4 06-01 21:19:52.126: I/jPCT-AE(6423): All texture data unloaded from gpu! 06-01 21:19:52.126: I/jPCT-AE(6423): Disposing VBOs! 06-01 21:19:52.151: I/jPCT-AE(6423): Renderer disposed! 06-01 21:19:52.151: I/jPCT-AE(6423): GLRenderer disposed with id 0 on Thread[GLThread 3989,5,main] 06-01 21:19:52.151: I/jPCT-AE(6423): GLRenderer created with id 1 on Thread[GLThread 3989,5,main] 06-01 21:19:52.151: I/jPCT-AE(6423): OpenGL vendor: ARM 06-01 21:19:52.151: I/jPCT-AE(6423): OpenGL renderer: Mali-400 MP 06-01 21:19:52.151: I/jPCT-AE(6423): OpenGL version: OpenGL ES-CM 1.1 06-01 21:19:52.151: I/jPCT-AE(6423): OpenGL renderer initialized (using 2 texture stages) 06-01 21:19:52.156: I/jPCT-AE(6423): Allocating native memory for 128*128 texture(true/false/false/false/): 65536 bytes! 06-01 21:19:52.156: I/jPCT-AE(6423): New texture's id is: 1 06-01 21:19:52.156: I/jPCT-AE(6423): New texture uploaded: com.threed.jpct.Texture@41c23f10 in thread Thread[GLThread 3989,5,main] 06-01 21:19:52.156: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.156: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.156: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.156: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.156: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.156: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.156: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.156: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.156: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.156: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.156: I/jPCT-AE(6423): Allocating native memory for 1024*1024 texture(true/false/false/false/): 4194304 bytes! 06-01 21:19:52.331: I/jPCT-AE(6423): New texture's id is: 2 06-01 21:19:52.341: I/jPCT-AE(6423): New texture uploaded: com.threed.jpct.Texture@41c000b0 in thread Thread[GLThread 3989,5,main] 06-01 21:19:52.341: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.341: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.341: I/jPCT-AE(6423): Allocating native memory for 1024*1024 texture(true/false/false/false/): 4194304 bytes! 06-01 21:19:52.531: I/jPCT-AE(6423): New texture's id is: 3 06-01 21:19:52.566: I/jPCT-AE(6423): New texture uploaded: com.threed.jpct.Texture@41c30410 in thread Thread[GLThread 3989,5,main] 06-01 21:19:52.566: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.566: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.566: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.566: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.566: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.566: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.566: I/jPCT-AE(6423): Allocating native memory for 64*64 texture(true/false/false/false/): 16384 bytes! 06-01 21:19:52.566: I/jPCT-AE(6423): New texture's id is: 4 06-01 21:19:52.566: I/jPCT-AE(6423): New texture uploaded: com.threed.jpct.Texture@41c1efc0 in thread Thread[GLThread 3989,5,main] 06-01 21:19:52.566: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.566: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.571: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.571: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.571: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.571: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.571: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.571: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.571: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.571: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.571: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.571: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.571: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.571: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.571: I/jPCT-AE(6423): Allocating native memory for 128*32 texture(true/false/false/false/): 16384 bytes! 06-01 21:19:52.571: I/jPCT-AE(6423): New texture's id is: 5 06-01 21:19:52.576: I/jPCT-AE(6423): New texture uploaded: com.threed.jpct.Texture@41c0cd28 in thread Thread[GLThread 3989,5,main] 06-01 21:19:52.576: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.576: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.576: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.576: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.576: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.576: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.576: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.576: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.576: I/jPCT-AE(6423): Allocating native memory for 64*64 texture(true/false/false/false/): 16384 bytes! 06-01 21:19:52.576: I/jPCT-AE(6423): New texture's id is: 6 06-01 21:19:52.576: I/jPCT-AE(6423): New texture uploaded: com.threed.jpct.Texture@41bfbd78 in thread Thread[GLThread 3989,5,main] 06-01 21:19:52.576: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.581: I/jPCT-AE(6423): Creating buffers... 06-01 21:19:52.581: I/jPCT-AE(6423): OpenGL context has changed(2)...recovering for renderer 1/0! 06-01 21:19:52.581: I/jPCT-AE(6423): Creating buffers...

Does replaceTexture unload previous texture immediately? If not, there might be out of memory issue since the textures are quite huge. Can't afford to put multiple big textures in memory.
Title: Re: Strange looking preference activity in livewallpaper
Post by: EgonOlsen on June 01, 2013, 05:03:02 pm: No, it doesn't. It uploads the new (and removes the former) texture in the next render pass. But i don't see a huge problem with that as long as you aren't close to the memory limit all the time. In that case, you can use texture compression in memory and/or GPU.
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on June 02, 2013, 02:26:23 pm: Hi Egon,

I've solved the issue! By putting the method that removes textures in onSurfaceChanged(), it doesn't show square fonts anymore. I think there is gl context processing going on between onResume() and onSurfaceChanged(). The gl context is ready only at onSurfaceChanged(). All gl related methods shall not be put in onResume() and onPause(), else everything gets hay-wired.

BTW, thanks for being so helpful. Really appreciate it. Now we can have a peace of mind, at last.
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on June 21, 2013, 05:54:22 am: Hi Egon,

Sorry to bother you again on this case. I got another issue with preference activity. If I open the preference activity in preview wallpaper, then press the home button, the textures in preference activity are gone again.

This is the flow I can observe from the case above:
1. Preference activity opened
2. Engine paused
3. Home button pressed
4. Engine destroyed
5. Preference activity destroyed

Everything related to gl is disposed at engine's onDestroy(). Can it be that JPCT disposes objects using different context after preference context shows up and takes over gl context? This context thing is really pain in the a**. I have been debugging for few days solely on this.
Title: Re: Strange looking preference activity in livewallpaper
Post by: EgonOlsen on June 21, 2013, 07:39:40 am: How does the log output with logger set to debug looks in that case?
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on June 21, 2013, 07:52:02 am: Here's the log after home button is pressed while preference activity is visible.

Code: [Select]
06-21 13:49:17.093: D/GLWallpaperService(4406): onSurfaceDestroyed() 06-21 13:49:17.098: V/Kision(4406): Engine onDestroy(): com.kision.tapleaves.WallpaperService$WallpaperEngine@41a67e40 true 06-21 13:49:17.098: W/WallpaperService(4406): Ignoring updateSurface: destroyed 06-21 13:49:17.098: I/jPCT-AE(4406): Unloaded texture: 1 06-21 13:49:17.098: I/jPCT-AE(4406): Unloaded texture: 6 06-21 13:49:17.098: I/jPCT-AE(4406): Unloaded texture: 5 06-21 13:49:17.098: I/jPCT-AE(4406): Unloaded texture: 2 06-21 13:49:17.103: I/jPCT-AE(4406): Unloaded texture: 3 06-21 13:49:17.103: I/jPCT-AE(4406): Unloaded texture: 7 06-21 13:49:17.103: I/jPCT-AE(4406): Unloaded texture: 8 06-21 13:49:17.103: I/jPCT-AE(4406): Unloaded texture: 4 06-21 13:49:17.103: I/jPCT-AE(4406): Unloaded texture: 9 06-21 13:49:17.103: I/jPCT-AE(4406): All texture data unloaded from gpu! 06-21 13:49:17.103: I/jPCT-AE(4406): Disposing VBOs! 06-21 13:49:17.108: I/jPCT-AE(4406): Renderer disposed! 06-21 13:49:17.108: I/jPCT-AE(4406): GLRenderer disposed with id 4 on Thread[main,5,main] 06-21 13:49:17.108: I/jPCT-AE(4406): Memory usage before compacting: 28974 KB used out of 31431 KB. Max. memory available to the VM is 49152 KB. 06-21 13:49:17.108: D/dalvikvm(4406): WAIT_FOR_CONCURRENT_GC blocked 0ms 06-21 13:49:17.163: D/dalvikvm(4406): GC_EXPLICIT freed 16708K, 61% free 12267K/31431K, paused 2ms+9ms, total 54ms 06-21 13:49:17.163: I/jPCT-AE(4406): VBO disposed for object 'border1' 06-21 13:49:17.163: I/jPCT-AE(4406): VBO disposed for object 'border2' 06-21 13:49:17.163: I/jPCT-AE(4406): VBO disposed for object 'leaf1' 06-21 13:49:17.163: I/jPCT-AE(4406): VBO disposed for object 'leaf2' 06-21 13:49:17.163: I/jPCT-AE(4406): VBO disposed for object 'leaf3' 06-21 13:49:17.163: I/jPCT-AE(4406): VBO disposed for object 'leaf4' 06-21 13:49:17.163: I/jPCT-AE(4406): VBO disposed for object 'leavesGroup1' 06-21 13:49:17.163: I/jPCT-AE(4406): VBO disposed for object 'leavesGroup2' 06-21 13:49:17.163: I/jPCT-AE(4406): VBO disposed for object 'leavesGroup3' 06-21 13:49:17.163: I/jPCT-AE(4406): VBO disposed for object 'leavesGroup4' 06-21 13:49:17.163: I/jPCT-AE(4406): VBO disposed for object 'leavesGroup5' 06-21 13:49:17.163: I/jPCT-AE(4406): VBO disposed for object 'shadow1' 06-21 13:49:17.163: I/jPCT-AE(4406): VBO disposed for object 'shadow2' 06-21 13:49:17.163: I/jPCT-AE(4406): VBO disposed for object 'shadow3' 06-21 13:49:17.168: I/jPCT-AE(4406): VBO disposed for object 'shadow4' 06-21 13:49:17.168: I/jPCT-AE(4406): VBO disposed for object 'shadow5' 06-21 13:49:17.168: I/jPCT-AE(4406): VBO disposed for object 'shadow6' 06-21 13:49:17.168: I/jPCT-AE(4406): VBO disposed for object 'shadow7' 06-21 13:49:17.168: I/jPCT-AE(4406): VBO disposed for object 'BUTT08_jPCT188' 06-21 13:49:17.168: I/jPCT-AE(4406): VBO disposed for object 'BUTT08_jPCT188' 06-21 13:49:17.168: I/jPCT-AE(4406): VBO disposed for object 'BUTT07_jPCT189' 06-21 13:49:17.168: I/jPCT-AE(4406): VBO disposed for object 'BUTT07_jPCT189' 06-21 13:49:17.168: I/jPCT-AE(4406): VBO disposed for object 'BUTT09_jPCT187' 06-21 13:49:17.168: I/jPCT-AE(4406): VBO disposed for object 'object193' 06-21 13:49:17.168: I/jPCT-AE(4406): VBO disposed for object 'object193' 06-21 13:49:17.173: I/jPCT-AE(4406): VBO disposed for object 'object194' 06-21 13:49:17.173: I/jPCT-AE(4406): VBO disposed for object 'object194' 06-21 13:49:17.173: I/jPCT-AE(4406): VBO disposed for object 'object195' 06-21 13:49:17.173: I/jPCT-AE(4406): VBO disposed for object 'object197' 06-21 13:49:17.173: I/jPCT-AE(4406): VBO disposed for object 'object197' 06-21 13:49:17.173: I/jPCT-AE(4406): VBO disposed for object 'object198' 06-21 13:49:17.178: I/jPCT-AE(4406): VBO disposed for object 'object198' 06-21 13:49:17.178: I/jPCT-AE(4406): VBO disposed for object 'object199' 06-21 13:49:17.178: I/jPCT-AE(4406): VBO disposed for object 'object201' 06-21 13:49:17.178: I/jPCT-AE(4406): VBO disposed for object 'object201' 06-21 13:49:17.178: I/jPCT-AE(4406): VBO disposed for object 'object202' 06-21 13:49:17.178: I/jPCT-AE(4406): VBO disposed for object 'object202' 06-21 13:49:17.178: I/jPCT-AE(4406): VBO disposed for object 'object203' 06-21 13:49:17.178: I/jPCT-AE(4406): VBO disposed for object 'object205' 06-21 13:49:17.178: D/dalvikvm(4406): WAIT_FOR_CONCURRENT_GC blocked 0ms 06-21 13:49:17.183: I/jPCT-AE(4406): VBO disposed for object 'object205' 06-21 13:49:17.188: I/jPCT-AE(4406): VBO disposed for object 'object206' 06-21 13:49:17.188: I/jPCT-AE(4406): VBO disposed for object 'object206' 06-21 13:49:17.188: I/jPCT-AE(4406): VBO disposed for object 'object207' 06-21 13:49:17.188: I/jPCT-AE(4406): VBO disposed for object 'object209' 06-21 13:49:17.188: I/jPCT-AE(4406): VBO disposed for object 'object209' 06-21 13:49:17.188: I/jPCT-AE(4406): VBO disposed for object 'object210' 06-21 13:49:17.188: I/jPCT-AE(4406): VBO disposed for object 'object210' 06-21 13:49:17.188: I/jPCT-AE(4406): VBO disposed for object 'object211' 06-21 13:49:17.188: I/jPCT-AE(4406): VBO disposed for object 'object214' 06-21 13:49:17.193: I/jPCT-AE(4406): VBO disposed for object 'object215' 06-21 13:49:17.193: D/AbsListView(4406): [unregisterDoubleTapMotionListener] 06-21 13:49:17.193: I/MotionRecognitionManager(4406): .unregisterListener : / listener count = 0->0, ubvf 9budiwrd5ordgfl5BakTrklMrfo$,@,*e/a:d8 06-21 13:49:17.238: D/dalvikvm(4406): GC_EXPLICIT freed 802K, 64% free 11478K/31431K, paused 14ms+5ms, total 55ms 06-21 13:49:17.388: I/jPCT-AE(4406): Memory usage after compacting: 11479 KB used out of 31431 KB. Max. memory available to the VM is 49152 KB. 06-21 13:49:17.403: V/Kision(4406): Service onDestroy(): com.kision.tapleaves.WallpaperService@42080ce8 06-21 13:49:17.593: V/Kision(4406): Preference onDestroy(): com.kision.tapleaves.WallpaperPreferenceActivity@41a038d8
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on June 23, 2013, 04:44:28 pm: Hi Egon,

Does the log output look normal? I tried to the force finish the preference activity when the wallpaper preview called onDestroyed(), but still the preference activity called the onDestroy() after engine is destroyed. I've seen some cool wallpapers have been made with jPCT with no problem with preference activity. Have you encountered any of such issue with them before?
Title: Re: Strange looking preference activity in livewallpaper
Post by: EgonOlsen on June 23, 2013, 08:51:40 pm: Looks like as if the vbos get freed after the actual renderer has been disposed. This might happen if the garbage collected kicks in and tries to free the objects' memory. This might cause your problem and it actually shouldn't happen in this case. Try this version and see if it helps: http://jpct.de/download/beta/jpct_ae.jar (http://jpct.de/download/beta/jpct_ae.jar)
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on June 24, 2013, 09:30:13 am: It's still the same. I tried to free the vbos before engine onDestroy() too, but no luck on that.

Here's the log output if you need it for reference:
Code: [Select]
06-24 15:14:36.465: D/GLWallpaperService(16519): onSurfaceDestroyed() 06-24 15:14:36.465: I/jPCT-AE(16519): Unloaded texture: 6 06-24 15:14:36.470: I/jPCT-AE(16519): Unloaded texture: 4 06-24 15:14:36.470: I/jPCT-AE(16519): Unloaded texture: 3 06-24 15:14:36.470: I/jPCT-AE(16519): Unloaded texture: 1 06-24 15:14:36.470: I/jPCT-AE(16519): Unloaded texture: 5 06-24 15:14:36.470: I/jPCT-AE(16519): Unloaded texture: 7 06-24 15:14:36.470: I/jPCT-AE(16519): Unloaded texture: 2 06-24 15:14:36.470: I/jPCT-AE(16519): Unloaded texture: 8 06-24 15:14:36.470: I/jPCT-AE(16519): All texture data unloaded from gpu! 06-24 15:14:36.470: I/jPCT-AE(16519): Disposing VBOs! 06-24 15:14:36.475: I/jPCT-AE(16519): Renderer disposed! 06-24 15:14:36.475: I/jPCT-AE(16519): GLRenderer disposed with id 4 on Thread[main,5,main] 06-24 15:14:36.475: I/jPCT-AE(16519): Memory usage before compacting: 29218 KB used out of 31431 KB. Max. memory available to the VM is 49152 KB. 06-24 15:14:36.475: D/dalvikvm(16519): WAIT_FOR_CONCURRENT_GC blocked 0ms 06-24 15:14:36.555: D/AbsListView(16519): [unregisterDoubleTapMotionListener] 06-24 15:14:36.560: D/dalvikvm(16519): GC_EXPLICIT freed 17042K, 62% free 12177K/31431K, paused 10ms+13ms, total 84ms 06-24 15:14:36.570: I/MotionRecognitionManager(16519): .unregisterListener : / listener count = 0->0, ubvf 9budiwrd5ordgfl5BakTrklMrfo$,@,)(b(d)8 06-24 15:14:36.570: D/dalvikvm(16519): WAIT_FOR_CONCURRENT_GC blocked 0ms 06-24 15:14:36.635: D/dalvikvm(16519): GC_EXPLICIT freed 922K, 65% free 11256K/31431K, paused 2ms+3ms, total 64ms 06-24 15:14:36.785: I/jPCT-AE(16519): Memory usage after compacting: 11256 KB used out of 31431 KB. Max. memory available to the VM is 49152 KB. 06-24 15:14:36.790: V/Kision(16519): Engine onDestroy(): com.kision.tapleaves.WallpaperService$WallpaperEngine@41f068b0 true 06-24 15:14:36.790: W/WallpaperService(16519): Ignoring updateSurface: destroyed 06-24 15:14:36.810: V/Kision(16519): Service onDestroy(): com.kision.tapleaves.WallpaperService@41fb3a90 06-24 15:14:36.850: V/Kision(16519): Preference onDestroy(): com.kision.tapleaves.WallpaperPreferenceActivity@420344a8

IMHO, the gl context is switched to preference activity context when wallpaper settings show up. While the activity is active and home button is clicked, renderer is trying delete vbos using preference activity context. May be this causes the issue, presumably. I don't quite know how jPCT retains gl context, may be I can find some workarounds if I know better of it. Would love to listen to your suggestion.
Title: Re: Strange looking preference activity in livewallpaper
Post by: EgonOlsen on June 24, 2013, 11:02:24 am: jPCT-AE doesn't store the context in GL2.0 mode and in GL1.x mode, it stores the instance that you set when creating the FrameBuffer. Might be that this instance doesn't really reflect the actual context, but just provides a wrapper to the current one set Android somewhere, which would explain this issue. However, i'm not sure how to handle this. If the onSurfaceDestroyed() is being called for the gl view that shows the actual wallpaper, i would expect it to work with corresponding gl context. If it doesn't, what's the point in calling it anyway?

Have you tried to not dispose the FrameBuffer at all?
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on June 24, 2013, 04:24:40 pm: Yes, I tried it before. The memory seemed to leak alot without disposing the framebuffer.

Totally agree with the onSurfaceDestroy thingy. I was expecting that it should work accordingly too. Not sure if Android wallpaper has been designed in a too sophisticated way or it's just simply badly made. *fry squinting*

BTW, I made a few hacks into the existing GLWallpaperService to call another custom surfaceDestroy() method after the end of GLThread loop. It seems to work well now, but I'm still not sure if it is pointing the right context to dispose all objects correctly. The memory seems to leak but only till a limit. I'll continue to analyze it if it's workable, but meanwhile I would still love to hear other better alternatives.
Title: Re: Strange looking preference activity in livewallpaper
Post by: EgonOlsen on July 09, 2013, 09:27:28 pm: Maybe this helps: http://www.jpct.net/forum2/index.php/topic,3466.msg24912.html#msg24912 (http://www.jpct.net/forum2/index.php/topic,3466.msg24912.html#msg24912)
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on July 12, 2013, 06:07:49 pm: Hi Egon,

Thanx for the update. I tried the beta version with the fix, it seems like there is memory leak in live wallpaper.
Title: Re: Strange looking preference activity in livewallpaper
Post by: EgonOlsen on July 12, 2013, 06:11:20 pm: Caused by what? Remember that you still have to dispose the FrameBuffer.
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on July 13, 2013, 12:06:52 pm: I can't tell exactly what causes that, but I'm guessing VBOs and other objects are lost due to gl context changed and not being disposed. Since the WallpaperService object will stay as long as the livewallpaper is set to the phone, the lost VBOs or other objects are not be garbage collected within the WallpaperService object, IMHO.

Yes, I believe I did dispose the framebuffer.

Just in case, here's the debug log I recorded.
Code: [Select]
07-13 17:52:26.555: V/Kision(2283): Preference onPause(): com.kisionlab.tapleaves.WallpaperPreferenceActivity@4307aad8 07-13 17:52:26.890: D/GLWallpaperService(2283): onSurfaceDestroyed() 07-13 17:52:26.905: I/jPCT-AE(2283): [ 1373709146911 ] - WARNING: Unable to dispose gl related resources because the current context has changed! 07-13 17:52:26.905: I/jPCT-AE(2283): Renderer disposed! 07-13 17:52:26.905: I/jPCT-AE(2283): GLRenderer disposed with id 3 on Thread[main,5,main] 07-13 17:52:26.905: V/Kision(2283): onUniverseDestroyed! com.kisionlab.tapleaves.SceneSettingRenderer@42413898 07-13 17:52:26.905: V/Kision(2283): Engine onDestroy(): com.kisionlab.tapleaves.WallpaperService$WallpaperEngine@431b5b50 true 07-13 17:52:26.905: W/WallpaperService(2283): Ignoring updateSurface: destroyed 07-13 17:52:27.090: V/WallpaperService(2283): Display Width=480 Height=800 07-13 17:52:27.090: V/Kision(2283): Engine onResume(): com.kisionlab.tapleaves.WallpaperService$WallpaperEngine@42390d30 false 07-13 17:52:27.120: V/Kision(2283): onUniverseCreated! com.kisionlab.tapleaves.SceneSettingRenderer@42393538 07-13 17:52:27.120: V/Kision(2283): onUniverseChanged! com.kisionlab.tapleaves.SceneSettingRenderer@42393538 07-13 17:52:27.120: I/jPCT-AE(2283): Visibility lists disposed! 07-13 17:52:27.120: I/jPCT-AE(2283): [ 1373709147129 ] - WARNING: Unable to dispose gl related resources because the current context has changed! 07-13 17:52:27.120: I/jPCT-AE(2283): Renderer disposed! 07-13 17:52:27.125: I/jPCT-AE(2283): GLRenderer disposed with id 2 on Thread[GLThread 19049,5,main] 07-13 17:52:27.125: I/jPCT-AE(2283): GLRenderer created with id 4 on Thread[GLThread 19049,5,main] 07-13 17:52:27.125: I/jPCT-AE(2283): GL context is 1131742352 07-13 17:52:27.125: I/jPCT-AE(2283): OpenGL vendor: ARM 07-13 17:52:27.125: I/jPCT-AE(2283): OpenGL renderer: Mali-400 MP 07-13 17:52:27.125: I/jPCT-AE(2283): OpenGL version: OpenGL ES-CM 1.1 07-13 17:52:27.125: I/jPCT-AE(2283): OpenGL renderer initialized (using 2/8 texture stages) 07-13 17:52:27.130: I/jPCT-AE(2283): Allocating native memory for 64*64 texture(true/false/false/false/): 16384 bytes! 07-13 17:52:27.135: I/jPCT-AE(2283): New texture's id is: 9 07-13 17:52:27.135: I/jPCT-AE(2283): New texture uploaded: com.threed.jpct.Texture@4320c0e0 in thread Thread[GLThread 19049,5,main] 07-13 17:52:27.135: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.135: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.140: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.140: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.140: I/jPCT-AE(2283): Allocating native memory for 128*128 texture(true/false/false/false/): 65536 bytes! 07-13 17:52:27.145: I/jPCT-AE(2283): New texture's id is: 10 07-13 17:52:27.145: I/jPCT-AE(2283): New texture uploaded: com.threed.jpct.Texture@423857f8 in thread Thread[GLThread 19049,5,main] 07-13 17:52:27.145: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.145: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.150: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.150: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.150: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.150: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.150: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.150: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.150: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.150: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.150: I/jPCT-AE(2283): Allocating native memory for 1024*1024 texture(true/false/false/false/): 4194304 bytes! 07-13 17:52:27.190: D/dalvikvm(2283): GC_FOR_ALLOC freed 8988K, 32% free 20870K/30535K, paused 40ms, total 40ms 07-13 17:52:27.195: I/dalvikvm-heap(2283): Grow heap (frag case) to 25.015MB for 4194320-byte allocation 07-13 17:52:27.235: D/dalvikvm(2283): GC_CONCURRENT freed 876K, 22% free 24089K/30535K, paused 12ms+4ms, total 41ms 07-13 17:52:27.235: D/dalvikvm(2283): WAIT_FOR_CONCURRENT_GC blocked 26ms 07-13 17:52:27.260: D/dalvikvm(2283): GC_FOR_ALLOC freed <1K, 22% free 24089K/30535K, paused 23ms, total 23ms 07-13 17:52:27.260: I/dalvikvm-heap(2283): Grow heap (frag case) to 28.160MB for 4194320-byte allocation 07-13 17:52:27.260: D/dalvikvm(2283): WAIT_FOR_CONCURRENT_GC blocked 55ms 07-13 17:52:27.305: D/dalvikvm(2283): GC_FOR_ALLOC freed 0K, 8% free 28185K/30535K, paused 41ms, total 41ms 07-13 17:52:27.385: I/jPCT-AE(2283): New texture's id is: 11 07-13 17:52:27.385: D/AbsListView(2283): [unregisterDoubleTapMotionListener] 07-13 17:52:27.385: I/MotionRecognitionManager(2283): .unregisterListener : / listener count = 0->0, ubvf 9budiwrd5ordgfl5BakTrklMrfo$,@,+-.ebb( 07-13 17:52:27.400: I/jPCT-AE(2283): New texture uploaded: com.threed.jpct.Texture@423a4488 in thread Thread[GLThread 19049,5,main] 07-13 17:52:27.400: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.400: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.400: I/jPCT-AE(2283): Allocating native memory for 1024*1024 texture(true/false/false/false/): 4194304 bytes! 07-13 17:52:27.420: D/dalvikvm(2283): GC_CONCURRENT freed 14K, 8% free 28175K/30535K, paused 72ms+4ms, total 115ms 07-13 17:52:27.420: D/dalvikvm(2283): WAIT_FOR_CONCURRENT_GC blocked 19ms 07-13 17:52:27.440: D/dalvikvm(2283): GC_FOR_ALLOC freed 8192K, 35% free 19983K/30535K, paused 22ms, total 22ms 07-13 17:52:27.445: I/dalvikvm-heap(2283): Grow heap (frag case) to 24.150MB for 4194320-byte allocation 07-13 17:52:27.465: D/dalvikvm(2283): GC_FOR_ALLOC freed 0K, 22% free 24079K/30535K, paused 24ms, total 24ms 07-13 17:52:27.490: D/dalvikvm(2283): GC_FOR_ALLOC freed 0K, 22% free 24079K/30535K, paused 21ms, total 21ms 07-13 17:52:27.490: I/dalvikvm-heap(2283): Grow heap (frag case) to 28.150MB for 4194320-byte allocation 07-13 17:52:27.680: D/dalvikvm(2283): GC_CONCURRENT freed 0K, 8% free 28175K/30535K, paused 154ms+5ms, total 189ms 07-13 17:52:27.680: D/dalvikvm(2283): WAIT_FOR_CONCURRENT_GC blocked 36ms 07-13 17:52:27.680: D/dalvikvm(2283): WAIT_FOR_CONCURRENT_GC blocked 36ms 07-13 17:52:27.680: D/dalvikvm(2283): WAIT_FOR_CONCURRENT_GC blocked 37ms 07-13 17:52:27.680: D/dalvikvm(2283): WAIT_FOR_CONCURRENT_GC blocked 37ms 07-13 17:52:27.680: V/Kision(2283): Preference onStop(): com.kisionlab.tapleaves.WallpaperPreferenceActivity@4307aad8 07-13 17:52:27.685: V/Kision(2283): Preference onDestroy(): com.kisionlab.tapleaves.WallpaperPreferenceActivity@4307aad8 07-13 17:52:27.695: I/jPCT-AE(2283): New texture's id is: 12 07-13 17:52:27.710: I/jPCT-AE(2283): New texture uploaded: com.threed.jpct.Texture@4239e220 in thread Thread[GLThread 19049,5,main] 07-13 17:52:27.710: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.710: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.710: I/jPCT-AE(2283): Allocating native memory for 8*8 texture(true/false/false/false/): 256 bytes! 07-13 17:52:27.710: I/jPCT-AE(2283): New texture's id is: 13 07-13 17:52:27.710: I/jPCT-AE(2283): New texture uploaded: com.threed.jpct.Texture@431ca698 in thread Thread[GLThread 19049,5,main] 07-13 17:52:27.710: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.710: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.715: I/jPCT-AE(2283): Allocating native memory for 64*64 texture(true/false/false/false/): 16384 bytes! 07-13 17:52:27.715: I/jPCT-AE(2283): New texture's id is: 14 07-13 17:52:27.715: I/jPCT-AE(2283): New texture uploaded: com.threed.jpct.Texture@431d4720 in thread Thread[GLThread 19049,5,main] 07-13 17:52:27.715: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.715: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.715: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.715: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.715: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.715: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.715: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.715: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.715: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.715: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.715: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.715: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.715: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.715: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.715: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.715: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.720: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.720: I/jPCT-AE(2283): Creating buffers... 07-13 17:52:27.720: I/jPCT-AE(2283): OpenGL context has changed(2)...recovering for renderer 4/2! 07-13 17:52:27.720: I/jPCT-AE(2283): Creating buffers...
The log above is made based on this test case:
1. Open preference activity while live wallpaper is set to phone.
2. Press home button
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on July 13, 2013, 12:14:56 pm: When GLRenderer is disposed, it is disposed on Main Thread (GLRenderer disposed with id 3 on Thread[main,5,main]), but when it is created, it's in GLThread (GLRenderer created with id 4 on Thread[GLThread 19049,5,main]). Does this cause the gl pointing to the wrong resources and dispose the wrong one?
Title: Re: Strange looking preference activity in livewallpaper
Post by: EgonOlsen on July 13, 2013, 01:31:49 pm: The vbos and similar structures that are bound to the GL context should be disposed when the GL context becomes invalid. The actual data in native memory isn't bound to the context anyway. The problem with all this context shit (sorry, i can't call it other than that) is, that i couldn't find any location other than the rendering thread where you can actually dispose these resources and that isn't an option in most cases.
Have you tried to debug the memory leak in Eclipse? Maybe it's something completely different anyway.
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on July 18, 2013, 05:36:31 pm: Sorry for replying late. Was busy these few days.

I tested out with eclipse MAT and both cases (disposing framebuffer and other stuff at engine's onDestroy() and the end of rendering thread respectively) seem to be almost same. Still new in eclipse MAT, BTW.

However, the memory status in android seems to be different though.
1. Dispose at engine's onDestroy() with jpct-ae beta: Memory can go as low as 80-90MB.
2. Dispose at the end of rendering thread: Memory gets low but maintains around 150MB.

*Both cases are tested when live wallpaper is set to phone and home button is pressed at wallpaper preference activity.

BTW, why is it a bad idea to dispose at rendering thread?
Title: Re: Strange looking preference activity in livewallpaper
Post by: EgonOlsen on July 18, 2013, 11:37:08 pm: Quote from: kkl on July 18, 2013, 05:36:31 pm
BTW, why is it a bad idea to dispose at rendering thread?
Not sure if it is...are you judging this based on the memory usage? However...this "leak"...is it really a leak, so that after some iterations, there's no memory left? Or it just that more memory is being used than you think it should?
Title: Re: Strange looking preference activity in livewallpaper
Post by: kkl on July 19, 2013, 03:49:43 am: Quote
However...this "leak"...is it really a leak, so that after some iterations, there's no memory left

I couldn't be sure about that too. But it just seems to take more memory than usual. The memory left seems to maintain at one extent.

Quote
Or it just that more memory is being used than you think it should
I guess so. The same objects and same textures should take equal amount of memory, shouldn't it?