Strange looking preference activity in livewallpaper

Started by kkl, May 28, 2013, 04:45:58 AM

Previous topic - Next topic

EgonOlsen

No, because the FrameBuffer is bound to the context. Not the new FrameBuffer causes the delay, but the context change.

kkl

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?

EgonOlsen

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.

kkl

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(). )

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.

EgonOlsen

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.

kkl

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.

kkl

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.

EgonOlsen

How does the log output with logger set to debug looks in that case?

kkl

Here's the log after home button is pressed while preference activity is visible.


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


kkl

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? 

EgonOlsen

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

kkl

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:

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.

EgonOlsen

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?

kkl

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.