firebase / quickstart-unity

Firebase Quickstart Samples for Unity
https://firebase.google.com/games
Apache License 2.0
835 stars 433 forks source link

Freeze on FirebaseRemoteConfig.ActivateFetched() Unity 2017.4.6f1 Android #182

Closed DenizPiri closed 6 years ago

DenizPiri commented 6 years ago

When calling FirebaseRemoteConfig.ActivateFetched() at the start of the app, at first frame, the app gets stuck in launch screen image. There seem to be no apparent errors in "adb logcat" output. This normally happens with 95% chance.

Deferring the ActivateFetched call by 100ms reduces the chances of getting this launch freeze a lot. In this case, chances of freezing is around 5%.

This is how my current initialization code looks like:

Firebase.FirebaseApp.CheckAndFixDependenciesAsync().ContinueWith(task =>
        {
            var dependencyStatus = task.Result;
            MainThreadDeferer.Instance.CallOnUnityThread(() =>
            {
                if (Debug.isDebugBuild)
                    Debug.LogFormat("Firebase.DependencyStatus: {0}", dependencyStatus);

                if (dependencyStatus == Firebase.DependencyStatus.Available)
                {
                    // Fetch and activate firebase remote config data.
                    Run.AfterRealtime(0.1f, () => // WARNING: Without this ActivateFetched gets stuck on Android sometimes.
                    {
                        Firebase.RemoteConfig.FirebaseRemoteConfig.ActivateFetched();
                        Firebase.RemoteConfig.FirebaseRemoteConfig.FetchAsync().ContinueWith(task2 =>
                        {
                            MainThreadDeferer.Instance.CallOnUnityThread(() =>
                            {
                                if (Debug.isDebugBuild)
                                    Debug.LogFormat("Fetched firebase remote config");
                                Firebase.RemoteConfig.FirebaseRemoteConfig.ActivateFetched();
                            });
                        });
                    });
                }
                else
                {
                    UnityEngine.Debug.LogError(System.String.Format(
                      "Could not resolve all Firebase dependencies: {0}", dependencyStatus));
                    // Firebase Unity SDK is not safe to use here.
                }
            });
        });

MainThreadDeferer.Instance.CallOnUnityThread calls are there to defer the callbacks to main unity thread, just to make sure that task callbacks are not called in a separate thread.

Runtime I am on is Mono with .NET 2.0 Subset. Stripping level is set to "micro mscorlib". Min API level is Android 4.1, the target is Android 8.0. Building for ARMv7 arch.

I am puzzled by what might be causing the problem of being stuck. I wish firebase unity integration code was open source, would be pretty easy to understand what is going on. I assume that call is using some async API internally and waiting for the result in a while loop, just to be able to return the "bool" value. Then again, the Java API for activateFetched is not an async call. However, maybe, to get the call to the right thread, some async operation is going on there.

Would be great to get some help with this. I spent half the day battling with the error, still no clear solution. Deferring the ActivateFetched call by a constant time reduces chances of the problem happening, but doesn't fully solve it.

a-maurice commented 6 years ago

Thanks for alerting us to this issue. I'm not sure why it is hanging in that case, that's definitely odd behavior that we'll need to sort out.

That said, you should not need to do that first ActivateFetched() that your sample code has, as it is before the FetchAsync(). The basic flow it typically FetchAsync() -> after some time, the result are ready, but it still uses default / older values -> ActivateFetched() -> it now uses up to date values. So doing the ActivateFetched() prior to a Fetch should effectively be a no op, but it seems like something is going wrong there, which we will want to fix.

Also, both FetchAsync() and ActivateFetched() should be safe to call from any thread, not necessarily just the Unity main thread. In general, the only Firebase call that needs to be done from the Unity main thread is CheckAndFixDependenciesAsync, but if you need to do any interaction with game objects or other Unity calls, you will want to do something similar to what you have, with a dispatcher.

And unrelated, you will likely want to use FirebaseRemoteConfig.SetDefaults() to set default values for your remote config fields, prior to calling FetchAsync(). These are useful for when the user doesn't have internet connection, or if you just don't have anything set in the console for that value.

So, if you could try dropping that ActivateFetched() prior to the FetchAsync(), and see if that helps. If you are still having issues after that, please let us know!

DenizPiri commented 6 years ago

I built a fresh project by only importing FirebaseAnalytics.unitypackage and FirebaseRemoteConfig.unitypackage. I used the same initialization code from our game. Tried to start the app about 30 times, the freeze doesn't occur. However, when I move the FirebaseRemoteConfig calls outside of CheckAndFixDependenciesAsync callback. Same freeze occurs with a very high chance. This is the current code and last thing I see on logcat is "Firebase init 2". After that point, there are no errors and no other logs by the app.

Debug.LogFormat("Firebase init 0");
        Firebase.FirebaseApp.CheckAndFixDependenciesAsync().ContinueWith(task =>
        {
            var dependencyStatus = task.Result;
            if (dependencyStatus == Firebase.DependencyStatus.Available)
            {

            }
            else
            {
                UnityEngine.Debug.LogError(System.String.Format(
                  "Could not resolve all Firebase dependencies: {0}", dependencyStatus));
            }
        });
        Debug.LogFormat("Firebase init 1");

        Debug.LogFormat("Firebase init 2");
        Firebase.RemoteConfig.FirebaseRemoteConfig.SetDefaults(new Dictionary<string, object>());
        Debug.LogFormat("Firebase init 3");
        Firebase.RemoteConfig.FirebaseRemoteConfig.FetchAsync().ContinueWith(task2 =>
        {
            Debug.LogFormat("Firebase init 3.1");
            Firebase.RemoteConfig.FirebaseRemoteConfig.ActivateFetched();
            Debug.LogFormat("Firebase init 3.2");
        });
        Debug.LogFormat("Firebase init 4");

I believe whatever is causing the freeze with a very high chance, in this case, is causing the freeze in our app as well. I assume remote config tries to wait on a mutex or an event that never gets triggered. Or maybe some kind of deadlock because of locking order?

Why isn't the firebase unity adapter opensource? Isn't it just a bridge to the Android and iOS clients anyway? Would be great to see it's code, to get to know what I am dealing with. Currently, all I can do is to change call ordering, timing etc to hope that this freeze will not occur.

Here is the sample project: https://drive.google.com/open?id=1bTn811DcqAWGNgYWfw9hEMBUq8pUzR2c

DenizPiri commented 6 years ago

I found this issue here, that seems to be related to the issue I am having: https://stackoverflow.com/questions/41959490/firebase-makes-tasks-execute-only-on-main-thread-causing-unity-to-freeze

DenizPiri commented 6 years ago

Ok, I have been testing things with Development builds. Now that I switched to release builds, in our game even calling Firebase.FirebaseApp.CheckAndFixDependenciesAsync() causes a lock up. In this case not inside the call, but somewhere else (don't know where, yet). Possibly inside Unity.Tasks library?

I started to decompile Unity.Tasks library, to understand what is going on. I ran into a possible freeze. in Task.Wait() call. It is locking the mutex with Monitor.Enter() and right after that it checks IsCompleted property, IsCompleted implementation tries to lock the exact same mutex again. According to my knowledge, the default mutexes are not reentrant, however not sure how Unity's Mono C# runtime handles it.

a-maurice commented 6 years ago

Ah, you should not be using any Firebase calls until after CheckAndFixDependenciesAsync has finished. What it does is resolve any Android dependencies, which could potentially involve prompting the user to the Play store to update their Google Play Services, and trying to access Firebase features before that has finished can lead to unexpected behavior.

What we recommend, and what the testapps here do is: Firebase.FirebaseApp.CheckAndFixDependenciesAsync().ContinueWith(task => { var dependencyStatus = task.Result; if (dependencyStatus == Firebase.DependencyStatus.Available) { // Initialize Firebase here } else { UnityEngine.Debug.LogError(System.String.Format( "Could not resolve all Firebase dependencies: {0}", dependencyStatus)); } });

The reason for the odd behavior is that CheckAndFixDependenciesAsync potentially creates, and then destroys the default FirebaseApp, which Remote Config also uses. What is likely happening in this case is that the FirebaseApp that Remote Config is trying to use is getting destroyed as CheckAndFixDependencies is finishing, which is causing the freeze.

It sounds like moving that initialization logic into the continuation of CheckAndFixDependenciesAsync worked for you before, but if it does not, please let me know.

DenizPiri commented 6 years ago

Ok, I feel like I am not getting closer to figure it out using disassembled code.

I read the Tasks library by Parse, found it in an older version of their unity.net library. It overall seems to be fine. Found out that mutexes in C# are recursive by default. I see that there is a class called UnitySynchronizationContext in Firebase.Platform. I assumed that it should be used by default, however, I can't see any reference to it anywhere else. It might also be because of the decompiler.

One thing I noticed though is that, as far as I can tell from the decompiled code, SynchronizationContextBehavoir (typo in code) runs callbacks in Unity thread not in Update() callback but starts a coroutine at it's Start, and the coroutine invokes the callbacks. However, as far as I know, coroutines on DontDestroyOnLoad objects stop between scene changes. Maybe that behavior changed in newer versions, but as far as I know, this was the case in older unity versions. As for the couroutine itself, dotpeek fails to decompile that, so can't tell what is going on there.

Overall, I expect freezes to be originating from tasks library and SynchronizationContextBehavoir. I wish this lib didn't depend on .net Tasks at all. I don't know what more I can do at this point. It truly sucks that firebase lib is not open source. My current approach will be to remove firebase from our Unity based projects, as we cannot afford to release a game that fully freezes at any point. In meantime, I will eagerly wait for a fix by the Google Firebase team ⌛️⌛️⌛️

Cheers!

DenizPiri commented 6 years ago

@a-maurice As I pointed out, I get freezes even by simply using CheckAndFixDependenciesAsync(), especially that combined with a LoadScene that comes right after it. If I defer the LoadScene call by a second or two, then it works fine.

However, I really need to initialize firebase, start fetching the remote data and start loading the main menu all at once without even skipping a frame. Therefore, I would prefer it Firebase would use a normal TaskScheduler and I would be getting the init callback while unity is loading the main menu, and as a result, remote config fetching would start while unity is busy loading.

a-maurice commented 6 years ago

I've tried a handful of things, including the sample project you provided, and in release builds I have still been unable to reproduce a freeze with just CheckAndFixDependenciesAsync(), including with a call to LoadScene afterwards. If I do the FetchAsync() simultaneously, I do see a freeze, but as I mentioned that behavior is undefined, as the intention is that the task returned by CheckAndFixDependenciesAsync() needs to be finished before using any Firebase features, as otherwise some functionality might be missing, causing other failures. Have you been able to reproduce this in the remote config testapp that we provide?

Regarding your point above about SynchronizationContextBehavoir, that does seem like it might be an issue. There is actually a different MonoBehaviour that we ordinarily use for running functions on the main thread, which does use Update, but as you pointed out that SynchronizationContextBehavoir does not. We'll look into fixing this, but unfortunately I'm not sure if that will resolve the issue that you are seeing.

And thanks for the interest in open sourcing the Unity SDK. As you may have seen, both the iOS and Android SDKs have been moving more of their code to open source. The Unity libraries rely heavily on code generation, which makes it a bit harder than just exposing the cs files, but it's great to know that there is interest in it.

DenizPiri commented 6 years ago

In my experience, it is never ok for an API to lock up the thread. If it does, it means that there is a problem with the use of synchronization primitives. However, I can understand throwing an exception or returning an error code. In the sample project I provided, I placed the functions in that order just to increase the chances of the freeze. We don't do the initialization that way in our app.

I didn't try the remote config testapp you mention. Now I will try to have a reproducible freeze, by removing things from our app, instead of creating a new sample. Will post here when I have something.

DenizPiri commented 6 years ago

Ok, after spending 2 more days on it, I distilled our big project into a small case where I can create the freeze. It basically occurs when Firebase.FirebaseApp.CheckAndFixDependenciesAsync() called followed by a SceneManager.LoadScene() call, and then in the loaded scene, calling FirebaseRemoteConfig.GetValue(), it instantly freezes at that point. Once again, no exceptions, no logs.

Here is a sample project showing the freeze: https://drive.google.com/open?id=1-0N9M85SeUF4nNi1JJ716vhUOziyuMmn

If I move the SceneManager.LoadScene call within the ContinueWith callback of Firebase.FirebaseApp.CheckAndFixDependenciesAsync(), the freeze doesn't occur.

As I understand, only proper solution from our side is to make an independent load scene for firebase, and initialize it before we initialize anything else, but since it is async, it will go from our launch screen image to black screen (firebase initialize scene) then the actual intro scene, where we start initializing things which may be using firebase. Or wrap the whole firebase remote config API, cache the previous results ourselves, and use the previous value results if firebase callback is not called yet. Definitely not going for this option...

We are probably not going with a workaround like this since my trust in Firebase Unity SDK got fully crushed. We will opt for not using Firebase for our Unity based projects until all these possible cases of thread lock freezes disappear. As I mentioned before, under no condition an API should just block. Especially, when it is not a threading primitive itself or an async object. Also nowhere in Firebase Unity SDK docs it is mentioned that calling Firebase functions before CheckAndFixDependenciesAsync callback returns might lead to thread freezes.

Another suggestion would be to rename the CheckAndFixDependenciesAsync function. That naming completely sounds like an operation that is just there to check the dependencies. Not something that initializes an SDK and SDK being usable only after that async op completes.

a-maurice commented 6 years ago

Ah, that definitely clarifies the issue that you are seeing, as the loaded scene is trying to use Firebase as CheckAndFixDependenciesAsync is still running, so thank you for including that. And yes, if you want to start using Remote Config as soon as possible, then you would need to wait for CheckAndFixDependenciesAsync() to finish, as otherwise it is possible that the Android device does not have an up to date Google Play Services, which could cause exceptions being thrown, and other issues.

There are however alternatives to waiting for the initialization, if that is a concern. For example, you could use some default values for whatever fields you need, and then when both CheckAndFixDependenciesAsync and FetchAsync are finished, replace those with the fetched values. However, if you were looking to get the values before starting anything, then you would need to wait for both CheckAndFixDependenciesAsync and FetchAsync to be finished.

We do try to call out the need for CheckAndFixDependenciesAsync(), for example https://firebase.google.com/docs/remote-config/use-config-unity#initialize_the_sdk, but clearly we need to be doing a better job, so thank you for bringing that to our attention. And also thank you for bringing to our attention this freezing issue. While it is not the intention that other calls happen before CheckAndFixDepenciesAsync has finished, it should be throwing an exception, or something that can be handled, instead of potentially locking the game. We'll definitely work on getting a fix for that issue out.

DenizPiri commented 6 years ago

Ok, then the API is just wrong. Definitely not made for the way Unity works and the way most Unity projects are structured.

Most unity projects, in their first scene, have lots of objects that start doing things in their Awake/Start functions. Some of these things will naturally depend on a remote config value or trigger an analytics event. In Unity, there is no Init() function that runs before your scene starts or while the engine starts up. Best bet is to use a transient scene, but then if you spend more than a frame in that scene before your next LoadScene function, you end up clearing the launch image and screen goes black. So using CheckAndFixDependenciesAsync() in a transient scene and using that as the first scene which loads the actual intro/menu scene when Firebase initialization is done is also not an option, loading sequence ends up looking really ugly.

My current solution is to use Firebase.FirebaseApp.CheckDependencies in the first scene of the game, and do nothing before that. If it is Available, start a thread for fetching remote config (I also had a freeze with this previously, not trusting it anymore) proceed with using SceneManager.LoadScene. If CheckDependencies doesn't return a positive result, then call FixDependenciesAsync and in that case wait for its result to run the LoadScene call. However, as I understand even this is not a solution enough, because now I cannot know how the game will behave, for example, on an Amazon Kindle device. It might simply just freeze because of the uninitialized firebase. So I need to wrap all firebase APIs that I am using so that I can replace it with dummy implementations in case firebase didn't initialize properly.

I still can't declare this issue fully solved for our project's goal, we need more testing on more devices, especially the ones without Google Play Services. I also need to measure the timing of CheckDependencies function to make sure that we don't add an unnecessary 1-2 secs to our game's loading time.

From a API user's perspective I would expect the following:

Please don't close this issue at least until the freeze issue is completely resolved.

Cheers!

DenizPiri commented 6 years ago

I measured the timing of CheckDependencies function, seems to be taking ~300ms on Galaxy S9, and 500 to 900ms 🔥 on Xperia Z3. 😞😞😞

stewartmiles commented 6 years ago

@DenizPiri as @a-maurice pointed out, almost all Google, including Firebase, APIs on Android require Google Play services at the moment. This includes Remote Config which consists of the client library (bit you ship with your app) and the daemon / APK which is distributed to every Google Play Android device. Each time the client SDK moves to the latest version the daemon / APK needs to be new enough to support the client. We need to perform the check for the latest Google Play services / upgrade it to the required version to start using the Remote Config API on Android.

Now to each of your points...

Now as you describe the process of performing a local RPC on device to check that Google Play services is up to date is very slow. The 900ms seems crazy to me, running this in parallel seems like a long time as well especially if you have code dependent upon the library being initialized. I've filed a bug against the team that owns this.

I recommend starting asynchronously initializing the SDK from whatever code paths you have that lead to a call into Firebase. For example, while collaborating with @dzlier-gcp on Firebase Unity Solutions we came across a similar issue and solved it using this FirebaseInitializer.cs class which can be called from multiple entry points (i.e multiple behaviors) which then provides a signal when initialization is complete.

Given the constraints of the current Android SDK structure we would be happy to hear suggestions on how it could be improved.

DenizPiri commented 6 years ago

First of all, I would like to thank you both for taking your time and paying attention to the issues I am raising. This already put you way ahead of all the other open/closed source libs out there. 👏👏👏

Going to reply to the replies you have given.

Anyway, once again thanks for your time. As I mentioned previoulsy, now using CheckDependencies as the first thing in the game and starting the actual game scene only after that works for us currently. Hopefully, we won't run into any other freeze issue. I will be looking forward for the freeze fix and a definitely a version where some parts of the API can work without requiring initialization. So, I will get back to my usual tasks, and will be on the lookout for future releases! ⌛️

Cheers! 🥂

DenizPiri commented 6 years ago

One thing I forgot to mention. I can completely understand not changing the naming of CheckAndFixDependenciesAsync for the sake of not breaking existing user's integrations. However, that could be always be marked as deprecated 😄

stewartmiles commented 6 years ago

@DenizPiri we tracked down the source of slowness. It turns out that simply checking whether Google Play Services is up to date can take a very long time. So we've changed initialization to attempt to initialize the Android libraries first and if anything fails, due to Google Play Services being out of date, we then run the update check.

This was added in 5.3.0 https://firebase.google.com/support/release-notes/unity#5.3.0 even though it looks like it didn't make it to the release notes. I hope this works out.

DenizPiri commented 6 years ago

@stewartmiles Great! Thanks!!!

While reading the changelog, I noticed this: "Firebase now throws an exception if any Firebase libraries are initialized while CheckAndFixDependenciesAsync() is still in progress.". This addresses my main complaint fully.

Thanks once again! ❤️

stewartmiles commented 6 years ago

Thanks @DenizPiri , @a-maurice sorted out the race with CheckAndFixDependenciesAsync(), I just get to announce stuff :+1:

DenizPiri commented 6 years ago

@a-maurice Thank you!!! ❤️

AbhijitTaneja commented 5 years ago

I am stilll facing this issue on Unity 5.6.3 p4 and firebase sdk 5.4.0. Need help!!!

alexames commented 5 years ago

@AbhijitTaneja, can you provide more detail? Did you confirm you're not calling any other Firebase API functions until CheckAndFixDependenciesAsync() has completed? What error are you getting?

AbhijitTaneja commented 5 years ago
Firebase.FirebaseApp.CheckAndFixDependenciesAsync().ContinueWith(task =>
        {
            var dependencyStatus = task.Result;
            if (dependencyStatus == Firebase.DependencyStatus.Available)
            {
                app = Firebase.FirebaseApp.DefaultInstance;

                Dictionary<string, object> defaultConfigDictionary = new Dictionary<string, object>();
                for (int i = 0; i < _ConfigKeyValuePair.Length; i++)
                    defaultConfigDictionary.Add(_ConfigKeyValuePair[i]._ConfigKey, "");

                Firebase.RemoteConfig.FirebaseRemoteConfig.SetDefaults(defaultConfigDictionary);
------------------------------**line**.................
            }
            else
                Debug.LogError(System.String.Format("Could not resolve all Firebase dependencies: {0}", dependencyStatus));
        });

If I try to call ActivateFetched, at line step, the execution never reaches that step. If I try to call ActivatedFetch at any other time, I get "ApplicationException: internal::IsInitialized() " exception

AbhijitTaneja commented 5 years ago

Also, this issue only happens on device, and not on unity editor

alexames commented 5 years ago

When you say that the "line" step never gets reached, are you saying that the call to SetDefaults never returns? Does the rest of that function run?

Do you also see this issue when running the quickstart testapp? I don't see any obvious errors in your code, so it would be good to know if it's happening in the quickstart too. If the quickstart app works, then we can start looking for things you might be doing differently from it.