search

godotengine / godot

Godot Engine – Multi-platform 2D and 3D game engine
https://godotengine.org
MIT License
91.47k stars 21.27k forks source link

Android app freezes until I lock and then unlock the phone (release build) #33956

Closed Toshiwoz closed 5 years ago

Toshiwoz commented 5 years ago

Godot version: 3.2 Beta 2

OS/device including version: Android 3.18.19

Issue description: I have exported my game to an APK without debug, by using the export dialog window. The app runs, I see the godot splash screen and the homescreen of my game image But as I load the first level, the app freezes, but only the visual part, as I was checking the output of adb logcat with this: adb logcat godot:I ActivityManager:I *:S And I could notice that the resource where loading, threads working, everything from a log standpoint was fine.

But here comes the weirdest thing, if I lock the phone screen, and unlock it, the level is there, working as if nothing. So, as suggested I tried with debug enabled, and in that case everything works!

I'm not in a hurry but I'd really like some help here.

Steps to reproduce: That's the problem, unless I release the code of my game I don't think I can reproduce the same error on another one.

Minimal reproduction project: That's the problem, unless I release the code of my game I don't think I can reproduce the same error on another one.

Toshiwoz commented 5 years ago

Ok, hee some logcats: --------- beginning of crash --------- beginning of system

11-27 16:53:31.020  1085  1830 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:53:31.773  1085  2156 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:53:36.021  1085  2177 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:53:41.022  1085  1947 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:53:46.023  1085  2155 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:53:51.024  1085  1095 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:53:56.025  1085  1946 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:54:01.025  1085  1830 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:54:01.837  1085  1095 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:54:06.026  1085  2108 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
--------- beginning of main
11-27 16:54:11.027  1085  2164 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:54:16.028  1085  1095 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:54:21.029  1085  2576 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:54:22.038  1085  1085 I ActivityManager: onWakefulnessChanged: 1
11-27 16:54:24.321  1085  1100 I ActivityManager: Start proc 13654:com.android.cellbroadcastreceiver/u0a2 for broadcast com.android.cellbroadcastreceiver/.transaction.CellBroadcastReceiver
11-27 16:54:24.358  1085  2177 W ActivityManager: Skip forceProcessStateUpTo() to newState 11
11-27 16:54:25.239  1085  2108 W ActivityManager: Unable to start service Intent { act=com.huawei.lcagent.RESUME_UPLOAD cmp=com.huawei.phoneservice/com.huawei.logupload.LogUploadService (has extras) } U=0: not found
11-27 16:54:26.030  1085  2164 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:54:27.349  1085  1106 I ActivityManager: [AppLaunch] Displayed Displayed com.android.systemui/.recent.RecentsActivity: +210ms
11-27 16:54:28.857  1085  1095 W ActivityManager: Finishing task with all activities already finished
11-27 16:54:28.857  1085  1095 W ActivityManager: Duplicate finish request for ActivityRecord{569a510 u0 com.android.systemui/.recent.RecentsActivity t354 f}
11-27 16:54:28.887  1085  2164 I ActivityManager: Activity reported stop, but no longer stopping: ActivityRecord{569a510 u0 com.android.systemui/.recent.RecentsActivity t354 f} state:FINISHING Callers=com.android.server.am.ActivityManagerService.activityStopped:7880 android.app.ActivityManagerNative.onTransact:556 com.android.server.am.ActivityManagerService.onTransact:2907 com.android.server.am.HwActivityManagerService.onTransact:393
11-27 16:54:28.938  1085  2108 I ActivityManager: Killing 13169:com.google.android.apps.photos/u0a94 (adj 15): empty #14
11-27 16:54:28.954  1085  1685 I ActivityManager: Killing 6567:com.android.settings/1000 (adj 16): remove task
11-27 16:54:29.032  1085  1685 I ActivityManager: Force stopping com.deependhulla.opensync appid=10116 user=0: from pid 1759by app
11-27 16:54:29.032  1085  1685 I ActivityManager: Killing 12716:com.deependhulla.opensync:sync/u0a116 (adj 11): stop com.deependhulla.opensyncfrom pid 1759by app
11-27 16:54:29.044  1085  1685 I ActivityManager: Killing 12730:com.deependhulla.opensync/u0a116 (adj 11): stop com.deependhulla.opensyncfrom pid 1759by app
11-27 16:54:29.074  1085  1096 I ActivityManager: Force stopping mini.space appid=10511 user=0: from pid 1759by app
11-27 16:54:29.142  1085  2576 W ActivityManager: Scheduling restart of crashed service com.android.settings/.deviceinfo.UsbConnectedService in 1000ms
11-27 16:54:30.153  1085  1100 I ActivityManager: Start proc 13701:com.android.settings/1000 for service com.android.settings/.deviceinfo.UsbConnectedService
11-27 16:54:30.153  1085  1100 I ActivityManager: [Background Service Priority Adjustment] Process.setProcessGroup to Process.THREAD_GROUP_BG_NONINTERACTIVE, app.pid: 13701
11-27 16:54:31.030  1085  2155 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:54:31.931  1085  1096 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:54:35.033  1085  1466 I ActivityManager: Start proc 13727:mini.space/u0a511 for activity mini.space/com.godot.game.GodotApp
11-27 16:54:35.077  1085  2177 I ActivityManager: Config changes=480 {1.0 740mcc2mnc es_EC ldltr sw360dp w598dp h336dp 320dpi nrml land night finger -keyb/v/h -nav/h suim:1 s.40}
11-27 16:54:35.586  1085  1096 I ActivityManager: Start proc 13746:com.android.vending/u0a38 for service com.android.vending/com.google.android.finsky.billing.iab.InAppBillingService
11-27 16:54:35.871 13727 13745 I godot   : Godot Engine v3.2.beta2.official - https://godotengine.org
11-27 16:54:35.923  1085  1106 I ActivityManager: [AppLaunch] Displayed Displayed mini.space/com.godot.game.GodotApp: +901ms
11-27 16:54:35.925 13727 13745 I godot   : Using GLES2 video driver
11-27 16:54:35.926 13727 13745 I godot   : godot: ENABLING GL DEBUG
11-27 16:54:35.926 13727 13745 I godot   : OpenGL ES 2.0 Renderer: Mali-T720
11-27 16:54:35.928 13727 13745 E godot   : **ERROR**: GL ERROR: Source: OpenGL  Type: Error     ID: 34  Severity: High
        Message: Error:glTexImage2D::<format> is not an accepted value
11-27 16:54:35.928 13727 13745 E godot   :    At: drivers/gles2/rasterizer_gles2.cpp:133:_gl_debug_print() - GL ERROR: Source: OpenGL   Type: Error     ID: 34  Severity: High  Message: Error:glTexImage2D::<format> is not an accepted value
11-27 16:54:35.928 13727 13745 E godot   : **ERROR**: GL ERROR: Source: OpenGL  Type: Error     ID: 34  Severity: High
        Message: Error:glTexImage2D::<format> is not an accepted value
11-27 16:54:35.928 13727 13745 E godot   :    At: drivers/gles2/rasterizer_gles2.cpp:133:_gl_debug_print() - GL ERROR: Source: OpenGL   Type: Error     ID: 34  Severity: High  Message: Error:glTexImage2D::<format> is not an accepted value
11-27 16:54:36.031 13727 13745 I godot   :
11-27 16:54:36.032  1085  1830 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:54:36.349 13727 13745 I godot   : Loading resource: res://default_bus_layout.tres
11-27 16:54:36.350 13727 13745 I godot   : CORE API HASH: 0
11-27 16:54:36.350 13727 13745 I godot   : EDITOR API HASH: 0
11-27 16:54:36.426 13727 13745 I godot   : Loading resource: res://default_env.tres
11-27 16:54:36.445 13727 13745 E godot   : **WARNING**: Cannot allocate mipmaps for 3D post processing effects
11-27 16:54:36.445 13727 13745 E godot   :    At: drivers/gles2/rasterizer_storage_gles2.cpp:4916:_render_target_allocate() - Cannot allocate mipmaps for 3D post processing effects

11-27 16:54:40.291  1085  1334 I ActivityManager: [Background Service Priority Adjustment] Set callerFg as false for service.getFlags():260
11-27 16:54:40.509  1085  1099 I ActivityManager: Start proc 13869:com.deependhulla.opensync:sync/u0a116 for service com.deependhulla.opensync/.syncadapter.CalendarsSyncAdapterService
11-27 16:54:40.587  1085  2158 I ActivityManager: Start proc 13883:com.deependhulla.opensync/u0a116 for service com.deependhulla.opensync/at.bitfire.cert4android.CustomCertService
11-27 16:54:41.033  1085  1946 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:54:43.195 13727 13745 I godot   : Loading resource: res://Ui/Icons/1x1/delapouite/ursa-major.svg
11-27 16:54:46.034  1085  2156 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:54:47.980  1085  1830 I ActivityManager: Start proc 13912:com.android.vending:download_service/u0a38 for service com.android.vending/com.google.android.finsky.downloadservice.DownloadService
11-27 16:54:49.732  1085  1466 I ActivityManager: Killing 13254:com.nextcloud.client/u0a124 (adj 15): empty #14
11-27 16:54:51.036  1085  1096 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:54:56.037  1085  1946 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:55:01.039  1085  2108 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:55:02.032  1085  1465 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:55:06.041  1085  2109 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:55:11.045  1085  1685 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:55:16.047  1085  1946 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:55:17.817  1085  2155 I ActivityManager: Killing 13300:com.rubenmayayo.reddit/u0a339 (adj 15): empty #14
11-27 16:55:21.048  1085  1685 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:55:26.050  1085  2576 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output

So everything fine till the above logs, then as I load the mentioned level I get:

11-27 16:56:16.069  1085  2156 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output

11-27 16:56:19.966 13727 13745 I godot   : No intersection found!
11-27 16:56:19.966 13727 13980 I godot   : Loading resource: res://Terrain/TerraGen/marsheight_cubemap/cs_px_01.jpg
11-27 16:56:20.462 13727 13745 I godot   : No intersection found!

11-27 16:56:21.070  1085  1096 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:56:21.423 13727 13980 I godot   : V Strip at: (0, 0, 1, 13340) - Path res://Terrain/TerraGen/marsheight_cubemap/cs_px_01.jpg:
11-27 16:56:21.475 13727 13745 I godot   : No intersection found!
11-27 16:56:21.486 13727 13980 I godot   : Loading resource: res://Terrain/TerraGen/marsheight_cubemap/cs_px_10.jpg
11-27 16:56:21.945 13727 13745 I godot   : No intersection found!
11-27 16:56:23.289 13727 13980 I godot   : H Strip at: (0, 0, 13340, 1) - Path res://Terrain/TerraGen/marsheight_cubemap/cs_px_10.jpg:
11-27 16:56:23.350 13727 13980 I godot   : Loading resource: res://Terrain/TerraGen/marsheight_cubemap/cs_px_00.jpg
11-27 16:56:23.449 13727 13745 I godot   : No intersection found!
11-27 16:56:25.965 13727 13745 I godot   : BuildingsManager intersect at (9.257324, -11.914185, 2.39444)
11-27 16:56:25.965 13727 13745 I godot   : astronaut_base intersect at (23.015625, -14.526367, -42.692261)
11-27 16:56:25.965 13727 13745 I godot   : rover_base intersect at (14.115967, 0.107666, -54.033203)
11-27 16:56:25.966 13727 13745 I godot   : drone_base intersect at (12.426025, 0.126709, -47.401123)
11-27 16:56:26.072  1085  1947 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:56:31.073  1085  2155 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:56:32.336  1085  1830 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:56:36.074  1085  1830 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output
11-27 16:56:41.075  1085  1685 W ActivityManager: getRunningAppProcesses: caller 10097 does not hold REAL_GET_TASKS; limiting output

(cleaned up the loading resources messages and some repeated ones) I do not see anything wrong here.

Calinou commented 5 years ago

Can you reproduce this in previous 3.2 betas or alphas? There's been many Android-related changes lately.

Toshiwoz commented 5 years ago

It worked! Using the 3.2 Alpha 3. So you're right, it's something that was added-modified in between.

akien-mga commented 5 years ago

I tried with https://github.com/quendera/TheSpinnerGame but couldn't reproduce the freeze in a release build, either with 3.2 beta 2 or the current master branch (0e6e64c9e9).

There are however some rendering errors relative to the device. Could you share your device model, and ideally its GLES report from http://opengles.gpuinfo.org/ ? If it's missing there, you can install https://play.google.com/store/apps/details?id=de.saschawillems.glescapsviewer to generate and upload the report for your phone model.

BTW,

Android 3.18.19

It seems unlikely that you're using Android Honeycomb from 2011 ;) https://en.wikipedia.org/wiki/Android_version_history#Android_3.0_Honeycomb_(API_11) 3.18.19 is your Linux kernel version, but not OS version.

akien-mga commented 5 years ago 
11-27 16:54:35.928 13727 13745 E godot   : **ERROR**: GL ERROR: Source: OpenGL  Type: Error     ID: 34  Severity: High
        Message: Error:glTexImage2D::<format> is not an accepted value
11-27 16:54:35.928 13727 13745 E godot   :    At: drivers/gles2/rasterizer_gles2.cpp:133:_gl_debug_print() - GL ERROR: Source: OpenGL   Type: Error     ID: 34  Severity: High  Message: Error:glTexImage2D::<format> is not an accepted value
11-27 16:54:35.928 13727 13745 E godot   : **ERROR**: GL ERROR: Source: OpenGL  Type: Error     ID: 34  Severity: High
        Message: Error:glTexImage2D::<format> is not an accepted value
11-27 16:54:35.928 13727 13745 E godot   :    At: drivers/gles2/rasterizer_gles2.cpp:133:_gl_debug_print() - GL ERROR: Source: OpenGL   Type: Error     ID: 34  Severity: High  Message: Error:glTexImage2D::<format> is not an accepted value

CC @clayjohn, but this is likely related to https://github.com/godotengine/godot/issues/33825#issuecomment-557820830 and fixed by bb1d75f55e / #33844.

11-27 16:54:36.426 13727 13745 I godot   : Loading resource: res://default_env.tres
11-27 16:54:36.445 13727 13745 E godot   : **WARNING**: Cannot allocate mipmaps for 3D post processing effects
11-27 16:54:36.445 13727 13745 E godot   :    At: drivers/gles2/rasterizer_storage_gles2.cpp:4916:_render_target_allocate() - Cannot allocate mipmaps for 3D post processing effects

This should be fixed by 5ab3b6152 / #33844.

@Toshiwoz Could you try with @Calinou's latest nightly build to see if the issue is fixed? It's not clear whether the above two GLES2 errors are responsible for the freeze, but at least they should now be fixed in the master branch.

Toshiwoz commented 5 years ago

Lol, sorry, you're right it's android 6. And the model is a Huawei Y6 (MYA-L11). I think this is the report: http://opengles.gpuinfo.org/displayreport.php?id=2747 Will later install and paste here info from the android app you suggest. And tonight I'll test the nightly build to see if it's solved.

Toshiwoz commented 5 years ago

Tested the nigthly build and it works. I mean, it loads the scene, it crashes after a while but I'm quite sure that's my code (now I'm 99% sure it works, fixing my code I do not have any crash neither screen freezed). So maybe it is that GLES error you mentioned @akien-mga. If you need some other tests or the logcat let me know.

clayjohn commented 5 years ago

Looks like it was fixed by #33844