My app crash randomly after a short period on release build but not on dev build

Unity Engine
,
1

Hello, I finished my app and when I test it on a release build, there is a sudden frame drop that lead to a permanent crash after 10 to 40 minutes (it really is random, happen anywhere in the game). At first, I thought it was the gameplay and that the Garbage Collector was overwhelmed at some point, or that I had memory leak problem despite the fact that we have a Garbage Collector. Then I just tested by just running the main menu who has really minimal amount of thing in it and it still crash randomly at the same rate.

So I decided to profile it and create a Development build. Now, for some reason I still haven’t manage to connect the profiler to my app, but one thing I notice is that the crash just never happen anymore. I ran the app for more than an hour on the menu screen, I played it, and yeah, some hiccup here and there (some optimization that still need to be done), but It never crash.

Is there something in dev mode that prevent the crash or something ? Because, if I can’t replicate the crash, even if I manage to profile it, I will have a hard time knowing what is going on.

2

Hey,

There had been a few instances where we had crash reproducing on release builds only, so that might be the case here as well. Could you give us more details about the problem? Unity version, logcat of the crash?

Regards,
Mantas

1 Like
3

Thank you for answering ! For logcat, well I’m still building some final features in the meantime and was planning on profiling later. The autoconnect option doesn’t work, even though I’m on the same network as my phone. My computer doesn’t have a network card that can connect to a wifi rooter, so I thought maybe that was the problem (was going to buy one). I’m not familiar in how to profile using the ADB package, so I don’t really know how to get the logcat .

Now what I can say is that I use Unity 2019.4.17. I used to have my project on 2020.1.14, but the game was just not opening anymore on my phone (was doing fine in the editor), so I used the LTS version of 2019. A note to have is that I started the project in the 2018 version, so maybe something got messed up when I updated, but I use a lot of nested prefab and new features from 2019 which really helped me in production.

1 Like
4

Autoconnect option or profiling doesn’t affect the ability to get logcat, also Wifi is also optional, if you have phone connected to PC via USB. Install Android Logcat package via Package Manager (https://docs.unity3d.com/Packages/com.unity.mobile.android-logcat@1.2/manual/index.html) it should help you getting the logcat for your app.

5

Oh ok. Will do. As for profiling, my phone is connected via USB, have the developer mode activated and I disable Mobile data, still get nothing in the profiler in Unity. Was going to use the ADB method, but seeing how unintuitive it was, I wanted to finish certain feature before getting into it.

Dumb question, if I install the logcat package and make a release build, will it work ? Like I said, the crash only occur in release build and not dev build.

6

Yes, logcat package can capture any log from any application no matter what config it was built. The difference in your case, because it will be non development build, there will be less log messages, but for crash output it will not matter, you should still get a stacktrace which you can resolve. P.S Don’t forget to tick Create Symbols option in Build Settings, as you will need the symbols inside for stacktrace resolving.

7

Hum ok, I wanted to tick the create symbol in build setting, but it is just not available. Do you have any idea why ? On a plus side, the log cat seem to work though (I switch to transfer photo on my phone and it worked, probably the reason I wasn’t able to profile too before).

6750091--778447--CreateSymbolProb.jpg
6750091--778447--CreateSymbolProb.jpg1167×1043 293 KB

8

I think it’s because you have mono selected (in Player Settings), that option is only available with il2cpp scripting backend. But you need to switch to il2cpp anyways, since you won’t be able to publish with mono

9

It was exactly that ! I will show you the log cat as soon as possible. Really a big thanks for your time !

10

Well, now it crash right at the beginning, but now that I have a logcat I can get some clue as too why. From the logcat, it is said that it is because of an out of range argument from an early routine being called. It doesn’t happen in the editor nor with mono version. I suspect that it is the following code that is erroneous. Since I can hear the music, but it crash at the introduction animation I feel like it is where the crash occur.

private IEnumerator Start()
    {
        while (GenericUIElementManager.instance == null ||AudioManager.instance == null )
        {
            yield return null;
        }

        genericUIElementManager = GenericUIElementManager.instance;
        audioManager = AudioManager.instance;
        audioManager.GoToUnpausedSnapshot();
        audioManager.FadeInPlay(GlobalEnum.SoundManagerName.MenuMusic.ToString());
    
        bestLevelReachedText.text = "Best Level Reached : " + Config.levelNames[PlayerDataManager.GetPlayerData().progressionIndex_record];
        bestTimeText.text = "Best Time : " + timeFormat(PlayerDataManager.GetPlayerData().timeToFinish_record);

        if (!SharedVariable.haveVisitedSplashScreen)
        {
            SharedVariable.haveVisitedSplashScreen = true;
            StartCoroutine(IntroductionAnimation());
        }
        else
        {
            InstantIntroduction();
        }
    }

I thought it was my trick to wait for the singleton to be active, but as I said the music is being called, so it can only be something after the loop.

Here is the copy paste of the error log :
2021-01-21 16:27:17.799 25845 25872 Error Unity ArgumentOutOfRangeException: Index and length must refer to a location within the string.
2021-01-21 16:27:17.799 25845 25872 Error Unity Parameter name: length
2021-01-21 16:27:17.799 25845 25872 Error Unity at System.String.Substring (System.Int32 startIndex, System.Int32 length) [0x00000] in <00000000000000000000000000000000>:0
2021-01-21 16:27:17.799 25845 25872 Error Unity at SplashScreenManager.timeFormat (System.Single timeToFormat) [0x00000] in <00000000000000000000000000000000>:0
2021-01-21 16:27:17.799 25845 25872 Error Unity at SplashScreenManager+d__17.MoveNext () [0x00000] in <00000000000000000000000000000000>:0
2021-01-21 16:27:17.799 25845 25872 Error Unity at UnityEngine.SetupCoroutine.InvokeMoveNext (System.Collections.IEnumerator enumerator, System.IntPtr returnValueAddress) [0x00000] in <00000000000000000000000000000000>:0
2021-01-21 16:27:17.799 25845 25872 Error Unity
2021-01-21 16:27:17.799 25845 25872 Error Unity (Filename: currently not available on il2cpp Line: -1)
2021-01-21 16:27:17.799 25845 25872 Error Unity

That being said, what I’m I suppose to do with the symbols.zip ? I tested with one build with the symbol and the other without, and the error message is the same. Do I just put the zip file in the same folder of the apk or is there anything else to do with it ?

11

Symbols.zip contains symbol files used for desymbolicating native stacktraces after the crash occurs, but from what you posted you’re getting an exception not a crash. Not sure if it will help, but in Player Settings, try settings C++ Configuration to Debug for Il2CPP, the stacktrace should contain line numbers. (Don’t forget to revert it back after done)

In case you’ll get a native crash, see this Stacktrace Utility | Android Logcat | 1.2.3 on how to desymbolicate it.

12

Ok yeah my bad, it was those line of code :

        bestLevelReachedText.text = "Best Level Reached : " + Config.levelNames[PlayerDataManager.GetPlayerData().progressionIndex_record];
        bestTimeText.text = "Best Time : " + timeFormat(PlayerDataManager.GetPlayerData().timeToFinish_record);

The save file was not created for that version of the game, I’m profiling to see where the crash will occur next on the release build (if it happen, the il2cpp version seem to load faster than the mono).

Ok thanks for the info !

13

I successfully made my app crash twice (one without zip, other with it). Problem is, I have nothing under the tag CRASH or Unity when it happen. I selected my app in the filter and got report for memory usage, and the continuous message I got from the log cat pretty much was always the same :

2021-01-21 18:54:15.131 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 4378(176KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1742KB/13MB, paused 192us total 19.506ms
2021-01-21 18:54:15.593 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 4368(176KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1742KB/13MB, paused 186us total 19.005ms
2021-01-21 18:54:16.096 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 4375(176KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1742KB/13MB, paused 179us total 16.506ms
2021-01-21 18:54:16.593 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 4377(176KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1742KB/13MB, paused 161us total 16.134ms
2021-01-21 18:54:17.132 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 4381(176KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1742KB/13MB, paused 170us total 16.104ms
2021-01-21 18:54:17.604 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 4371(176KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1742KB/13MB, paused 172us total 18.176ms
2021-01-21 18:54:18.178 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 4387(176KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1742KB/13MB, paused 182us total 17.989ms
2021-01-21 18:54:18.624 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 4368(176KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1742KB/13MB, paused 181us total 17.830ms
2021-01-21 18:54:19.142 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 4375(176KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1742KB/13MB, paused 154us total 18.716ms
2021-01-21 18:54:19.714 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 4389(176KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1742KB/13MB, paused 157us total 16.568ms

I tried to crash it a third time, but I ran it for more than 30 minutes as of now and still didn’t crash… I feel like it happen sooner when the application just got install.

I mean I say crash, but it just a big frame drop where the game still continue, but at a frame rate of like 1 image per 2 second and the music is still playing in the background. It also never come back and I have to restart the application for it to be fine.

14

Ok, it did it way after the time (and the frame rate started to drop progressively instead of suddenly) and now the average between the frame is like doubled:

2021-01-21 20:33:53.000 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 5303(238KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1800KB/13MB, paused 423us total 37.782ms
2021-01-21 20:33:53.318 32646 32646 Info ViewRootImpl ViewRoot’s Touch Event : ACTION_POINTER_UP(1)
2021-01-21 20:33:53.730 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 5286(240KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1800KB/13MB, paused 275us total 35.383ms
2021-01-21 20:33:53.891 32646 32646 Info ViewRootImpl ViewRoot’s Touch Event : ACTION_POINTER_DOWN(1)
2021-01-21 20:33:54.447 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 5382(240KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1800KB/13MB, paused 442us total 30.867ms
2021-01-21 20:33:54.933 32646 32646 Info ViewRootImpl ViewRoot’s Touch Event : ACTION_POINTER_UP(1)
2021-01-21 20:33:55.183 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 5232(224KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1800KB/13MB, paused 273us total 33.101ms
2021-01-21 20:33:55.301 32646 32646 Info ViewRootImpl ViewRoot’s Touch Event : ACTION_POINTER_DOWN(1)
2021-01-21 20:33:55.943 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 5473(240KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1800KB/13MB, paused 424us total 36.754ms
2021-01-21 20:33:56.251 32646 32646 Info ViewRootImpl ViewRoot’s Touch Event : ACTION_POINTER_UP(1)
2021-01-21 20:33:56.646 32646 32646 Info ViewRootImpl ViewRoot’s Touch Event : ACTION_POINTER_DOWN(1)
2021-01-21 20:33:56.681 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 5311(240KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1800KB/13MB, paused 274us total 33.735ms
2021-01-21 20:33:57.414 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 5389(240KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1784KB/13MB, paused 309us total 39.193ms
2021-01-21 20:33:58.118 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 5221(208KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1800KB/13MB, paused 360us total 37.129ms
2021-01-21 20:33:58.424 32646 32646 Info ViewRootImpl ViewRoot’s Touch Event : ACTION_POINTER_UP(1)
2021-01-21 20:33:58.800 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 5210(224KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1800KB/13MB, paused 317us total 34.455ms
2021-01-21 20:33:59.586 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 5057(208KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1800KB/13MB, paused 493us total 35.345ms
2021-01-21 20:34:00.258 32646 32646 Info ViewRootImpl ViewRoot’s Touch Event : ACTION_POINTER_DOWN(1)
2021-01-21 20:34:00.308 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 4998(208KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1816KB/13MB, paused 449us total 34.413ms
2021-01-21 20:34:01.022 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 5435(240KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1800KB/13MB, paused 295us total 35.779ms
2021-01-21 20:34:01.698 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 5108(208KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1800KB/13MB, paused 254us total 31.279ms
2021-01-21 20:34:01.891 32646 32646 Info ViewRootImpl ViewRoot’s Touch Event : ACTION_POINTER_UP(1)
2021-01-21 20:34:02.439 32646 32665 Info ctive.LaserBal Explicit concurrent copying GC freed 5167(224KB) AllocSpace objects, 1(20KB) LOS objects, 87% free, 1800KB/13MB, paused 337us total 34.766ms

still say that it is 87%free and the native heap still was the same though … Every game object in the scene is pooled. Part of the code is not 100% GC collect free for the primitive and certain object (like I instantiate new waitforseconds in some routine), but that’s it. From the start, I made sure that every game object in the game is pooled, from resources already available in the scene (I don’t even use Instantiate).

15

Close memory window in logcat, this should stop spamming Explicit concurrent copying GC freed

16

I mean, the spam is fine ? I also don’t see how to close the memory window ? It just that there is borderline nothing else. The only thing I notice is that the paused in ms is bigger during the ‘crash’.

Edit: Ok this is fine, I found it. I’m just not sure how it is helping me finding the problem since there is nothing else other than the touch event.

17

The stacktrace should be under tag Android Runtime/or CRASH if the app is really crashing, try disabling filtering by tag, and leave only filtering by process.

18

Yeah well I successfully made it ‘crash again’, but I got nothing under those filter. I didn’t disable memory, wanted to see if anything would happen. Well weirder thing is that the pause is still the same now (although I made it crash by just runing the main menu) … To make it quicker, I close and reboot my phone, it seem to help make this thing happen faster.

I check under CRASH and Android Runtime and it find nothing. You said filtering by process though ? No filter mean that I get alll sort of thing from my phone that is not related to the game.

19

Yes, you need to disable filtering by any tag, but keep your package selected, that way you’ll see only messages from your app.

20

Ok after a long testing, I think I have a clue about what is going on. I checked only message coming from the game package and there was nothing. So I turned my attention to just the phone in general.

So I did 2 test until it crash, one took around 20 minutes, other near to an hour, before the crash happen. I noted the time to when it happen so I can check only the error message coming only around that time.

First Test :
crash occur around 14:53:20

Thermal Engine:
2021-01-22 14:54:07.567 3658 3792 Error ThermalEngine TM Id ‘CHG_MONITOR’ Sensor ‘skin_pmic’ - alarm raised 3 at 37.1 degC
2021-01-22 14:55:32.643 3658 3792 Error ThermalEngine TM Id ‘WLCHG_MONITOR’ Sensor ‘skin_pmic’ - alarm raised 2 at 38.0 degC
2021-01-22 14:55:32.644 3658 3792 Info ThermalEngine ACTION: wireless_chg - Setting battery charging mitigation to 600 (default 0)
2021-01-22 14:57:01.840 3658 3790 Info ThermalEngine Thermal-Server: Thermal received msg from tmr_v2

Second Test:
crash occur around 16:52:10
2021-01-22 16:52:18.319 3411 3542 Error ThermalEngine TM Id ‘HIGH_TEMP_LCD_TUNE’ Sensor ‘vts’ - alarm raised 2 at 35.2 degC
2021-01-22 16:52:18.324 3411 3542 Info ThermalEngine ACTION: HT_LCD_TUNE - Setting LCD Leve to 1

Also, I didn’t took into note the first time but my wifi seem to have some issue around the same time of the crash :
2021-01-22 16:52:28.465 3997 4499 Error WifiVendorHal getWifiLinkLayerStats(l.940) failed {.code = ERROR_UNKNOWN, .description = errno: -95 (Unknown error -95)}
2021-01-22 16:52:31.481 3997 4499 Error WifiVendorHal getWifiLinkLayerStats(l.940) failed {.code = ERROR_UNKNOWN, .description = errno: -95 (Unknown error -95)}
2021-01-22 16:52:34.496 3997 4499 Error WifiVendorHal getWifiLinkLayerStats(l.940) failed {.code = ERROR_UNKNOWN, .description = errno: -95 (Unknown error -95)}
2021-01-22 16:52:37.510 3997 4499 Error WifiVendorHal getWifiLinkLayerStats(l.940) failed {.code = ERROR_UNKNOWN, .description = errno: -95 (Unknown error -95)}
2021-01-22 16:52:40.526 3997 4499 Error WifiVendorHal getWifiLinkLayerStats(l.940) failed {.code = ERROR_UNKNOWN, .description = errno: -95 (Unknown error -95)}
2021-01-22 16:52:43.542 3997 4499 Error WifiVendorHal getWifiLinkLayerStats(l.940) failed {.code = ERROR_UNKNOWN, .description = errno: -95 (Unknown error -95)}

It show up in the first test, but didn’t copy paste the log. My phone wasn’t hot for like an hour until the crash happen, where it got a little bit hotter.

So it seem to be occurring because of heat throttling. Although, why it is raised at just 35 degree in the second test is kind of weird. I already cap my FPS at 30 and I have optimize most of my shader (all of them custom …). Thermal engine sometime show up way before the crash, but the message say that the alarm is ‘cleared’, not 'raise. As soon as the message say ‘raise’, this is when the crash occur.

I will try to make the problem happen with a development version of the game. Maybe the test I did with it was just fluke (although I tested twice, for more than an hour)