firebase / firebase-js-sdk

Firebase Javascript SDK
https://firebase.google.com/docs/web/setup
Other
4.83k stars 891 forks source link

Firestore JS on Android fails to recover connection when returning from background #1060

Open mydoal opened 6 years ago

mydoal commented 6 years ago

[REQUIRED] Describe your environment

[REQUIRED] Describe the problem

Cordova Ionic app running Firestore JS fails to recover connection when returning form background. The console shows retries of attempts to re-establish connection. Only restarting the app resolves the problem.

This problem started a week ago after starting testing app on Android 7.1.1. The test used to run on Android 6.0 without any problems with the same version of all packages.

Steps to reproduce:

Open Cordova Android app running Angular+Firebase and do email authorization Move app to the background (pressing the Android home button) Wait a few minuts Reopen the app (we are still logged in) Open an angular page that uses Firestore api to retrieve a document

e.g.:

firebase.firestore().collection("profiles").doc(profileId).get()

The console shows multiple errors:

 {code: "auth/network-request-failed", message: "A network error (such as timeout, interrupted connection or unreachable host) has occurred."}

vendor.js:1 ERROR Error: Uncaught (in promise): FirebaseError: [code=aborted]: Failed to get document because the client is offline.
FirebaseError: Failed to get document because the client is offline.

ERROR Error: Uncaught (in promise): FirebaseError: [code=aborted]: Failed to get document because the client is offline.
FirebaseError: Failed to get document because the client is offline.

And fails to re-establish connection to Firestore:

vendor.js:1 ERROR nn
(anonymous) @ vendor.js:1
vendor.js:1 ERROR nn
(anonymous) @ vendor.js:1
vendor.js:1 ERROR nn
(anonymous) @ vendor.js:1
vendor.js:1 ERROR nn
(anonymous) @ vendor.js:1
vendor.js:1 ERROR nn

When turning on the log at debug level:

firebase.firestore().setLogLevel('debug')

We get some more information:

vendor.js:1 [2018-07-28T09:36:40.634Z]  @firebase/firestore: Firestore (4.10.1) [PersistentStream]: close with error: FirebaseError: [code=unknown]: Fetching auth token failed: A network error (such as timeout, interrupted connection or unreachable host) has occurred.
vendor.js:1 [2018-07-28T09:36:40.636Z]  @firebase/firestore: Firestore (4.10.1) [ExponentialBackoff]: Backing off for 2212.7402860971715 ms (base delay: 1500 ms)
...
vendor.js:1 [2018-07-28T09:37:43.017Z]  @firebase/firestore: Firestore (4.10.1) [PersistentStream]: close with error: FirebaseError: [code=unknown]: Fetching auth token failed: A network error (such as timeout, interrupted connection or unreachable host) has occurred.
vendor.js:1 [2018-07-28T09:37:43.018Z]  @firebase/firestore: Firestore (4.10.1) [ExponentialBackoff]: Backing off for 1865.6266004521462 ms (base delay: 2250 ms)
vendor.js:1 ERROR nn
...
vendor.js:1 [2018-07-28T09:39:52.641Z]  @firebase/firestore: Firestore (4.10.1) [PersistentStream]: close with error: FirebaseError: [code=unknown]: Fetching auth token failed: A network error (such as timeout, interrupted connection or unreachable host) has occurred.
vendor.js:1 [2018-07-28T09:39:52.644Z]  @firebase/firestore: Firestore (4.10.1) [ExponentialBackoff]: Backing off for 3589.0911531043184 ms (base delay: 5062.5 ms)
vendor.js:1 ERROR nn
...
vendor.js:1 [2018-07-28T09:43:24.775Z]  @firebase/firestore: Firestore (4.10.1) [Connection]: Creating WebChannel: https://firestore.googleapis.com/google.firestore.v1beta1.Firestore/Listen/channel [object Object]
vendor.js:1 [2018-07-28T09:43:25.632Z]  @firebase/firestore: Firestore (4.10.1) [Connection]: Opening WebChannel transport.
vendor.js:1 [2018-07-28T09:43:25.634Z]  @firebase/firestore: Firestore (4.10.1) [Connection]: WebChannel sending: {"database":"projects/xxx/(default)","addTarget":{"documents":{"documents":["projects/xxx/(default)/documents/profilesBadges/jRpVDzeqilsxbFRrCLBX"]},"targetId":16,"resumeToken":"CgkI0f6y0r7B3AI="}}
vendor.js:1 [2018-07-28T09:44:12.635Z]  @firebase/firestore: Firestore (4.10.1) [Connection]: WebChannel transport errored: Te
vendor.js:1 [2018-07-28T09:44:12.635Z]  @firebase/firestore: Firestore (4.10.1) [PersistentStream]: close with error: FirebaseError: [code=unavailable]: The operation could not be completed
...
vendor.js:1 [2018-07-28T09:56:15.635Z]  @firebase/firestore: Firestore (4.10.1) [Connection]: WebChannel transport errored: Te
vendor.js:1 [2018-07-28T09:56:15.636Z]  @firebase/firestore: Firestore (4.10.1) [PersistentStream]: close with error: FirebaseError: [code=unavailable]: The operation could not be completed
vendor.js:1 [2018-07-28T09:56:15.637Z]  @firebase/firestore: Firestore (4.10.1) [ExponentialBackoff]: Backing off for 64064.01037516744 ms (base delay: 60000 ms)
www.google.com/images/cleardot.gif?zx=dzwv0lyag6eu:1 Failed to load resource: net::ERR_CONNECTION_TIMED_OUT
...

After restarting the app everything continues to work,

While the console shows the errors, the app manages to make other RETS api calls via the network - there is a working internet connection

mydoal commented 6 years ago

Update:

  1. Adding the SHA-1 key to Firebase Console does not help.

  2. The problem has gotten worse:

When reloading the JS code, you cannot login to Firebase anymore:

{code: "auth/network-request-failed", message: "A network error (such as timeout, interrupted connection or unreachable host) has occurred."}

Only restarting the Android app running the JS in a webview manages to reset the problem.

mydoal commented 6 years ago

Update:

This issue is not happening on Android 6.0. Started happening on Android 7.1.1 Can this be related to the Doze and Background Optimizations introduced in Android 7.0?

https://developer.android.com/about/versions/nougat/android-7.0-changes

wilhuff commented 6 years ago

Unfortunately, this specific problem has nothing to do with Firestore. Firestore isn't even trying to connect: it's failing to get a token from Firebase Auth and not even trying to connect to its own backend:

vendor.js:1 [2018-07-28T09:36:40.634Z] @firebase/firestore: Firestore (4.10.1) [PersistentStream]: close with error: FirebaseError: [code=unknown]: Fetching auth token failed: A network error (such as timeout, interrupted connection or unreachable host) has occurred.

Firebase Auth, in turn is just doing basic XHRs to its backend. I strongly suspect something's up with Cordova + Android 7.1.1 but I don't know enough about it.

How are you signing in (if at all)?

mydoal commented 6 years ago

Thanks @wilhuff for your reply. I am signing in using firebase.auth.Auth.signInWithEmailAndPassword via AngularFire2.

The network is connected. I am able to make a rest api call in Angular from the same page while Firebase insists there in no connection

wti806 commented 6 years ago

@mydoal I cannot replicate the issue using android@7.1.1 and cordova@6.4.0. I tried to signInWithEmailAndPassword and pressed the home button. They reopened the app to make other rpc calls. It works fine for me. I did test on a emulator though. Does this issue only occur on real device?

mydoal commented 6 years ago

Thanks for your reply @wti806 . The problem occurs on a new LG Q6 Android 7.1.1 device. Same apk has been working fine on LG G4 Android 6 device for the past months. The problem occurs after the app is in the background for a few minutes (sometimes up to an hour) and then reopened. It seems as if Firestore is not aware that the network is back (probably after doze or standby). Network connection is definitely working. While Firestore keeps trying to connect and fail, other non Firebase Rest API calls are successful.

wti806 commented 6 years ago

@mydoal Can you replicate the issue on a 7.1.1 emulator before you deploy it to real device? The error is thrown from Auth component. I did try to move the app to background and then re-open. Didn't wait for an hour though. After that, I called a few Auth APIs to trigger REST calls and it works fine.

mydoal commented 6 years ago

@wti806 it works for me also if I wait for a few minutes. The device does not go into doze / standby mode in that timeframe. Only after > 30 min this happens. I will run it in an emulator and update here. I am not sure the emulator really emulates the doze / standby of a real device though.

mydoal commented 6 years ago

I am not sure that this an auth problem. Looks more like a Firebase / network problem. The auth will fail if there Firebase does not re-establish the connection.

wti806 commented 6 years ago

@mydoal I tested again and this time I waited for about 1 hour and half. Still cannot reproduce on with emulator. Please let me know if you can re-create this with emulator.

mydoal commented 6 years ago

This is from the remote console log. It goes on without stopping:

log1 error2

bojeil-google commented 6 years ago

I think firestore has some retrial policy to get a FIrebase ID token. It is failing for some reason. Network errors are hard to debug and replicate as they are likely to be environment related. Unless you can provide us with a clear way to replicate, there is little we can do here. Try changing networks, devices, build versions, call REST API directly, etc.

Also i noticed you are using version 4.12.1. Try upgrading to a newer version. There was an issue with navigator.onLine returning false when network is available. It was fixed in 4.13.0.

mydoal commented 6 years ago

@bojeil-google Thanks for the input regarding bug fix in 4.13.0. I will try to upgrade and update here. One more thing: When the exception is being thrown non-stop, I stopped the data on the phone and turned it back on. The application resumed working normally, i.e. Firebase started to get responses from the backend BUT the exception continued to be thrown in the background non-stop. Only restarting the app made it stop. Restarting Firebase network via api or reloading the angular page had no affect.

mydoal commented 6 years ago

@bojeil-google - is it possible to have someone at 'Component-Firestore' have a look too?

I think firestore has some retrial policy to get a FIrebase ID token. It is failing for some reason.

The label to this issue was changed to Component-Auth from Component-Firestore. It looks to me as a network problem and less than an auth problem. Thanks!

mydoal commented 6 years ago

@wti806 Cannot reproduce with Emulator. It closes the app when it is too long in the background. It does not seem to go to sooze/standby mode so I cannot test the affect of the network on the app.

mydoal commented 6 years ago

I was unaware that I accidentally closed the issue. Unfortunately it is still open...

bojeil-google commented 6 years ago

Please upgrade to 4.13.0 or after, your symptoms sounds similar to the navigator.onLine bug. You can also test it yourself. Check it after app is back in foreground, it is probably returning false.

mydoal commented 6 years ago

I've added the Codova plugin cordova-plugin-network-informatio and it seems to fix the problem.

It seems that you were right @bojeil-google. From looking in the javascript code: utils.js there is a comment there that relates to the navigator.online issue and the cordova plugin.

I will definitely try to upgrade to 4.13.0 however it will require regression tests for the whole system. I will update if it works without the plugin after the upgrade.

It might be helpful to add a more explicit comment about this in the release notes regarding the exception that is being thrown. This way, when people come across this situation (apparently there are quire a few issues opened about a similar experience), they will immediately know where to look for the answer.

Thank you all @bojeil-google @bojeil-google @wilhuff for your help. I appreciate it very much.

mydoal commented 6 years ago

Update: apparently adding the cordova-plugin-network-information plugin helped most of the time. However, there are some cases that firebase fails to recognize that the network has been re-established and continues throwing errors.

I've managed to upgrade to Firebase 4.13.0 and added a line in the log that shows the state of the network.

navigator['connection'].type //cordova-plugin-network-information

Unfortunately the problem did not go away. Its shows in the log that the network is connected to 4g and is available but Firebase thinks that the network if not connected and keeps sending errors to the console.

After sometime, Firebase realizes that the network is back and re-connects but there are cases that Firebase just keeps sending errors to the log until calling firebase.firestore().disableNetwork() and firebase.firestore().enableNetwork().

To summarize, adding the cordova-plugin-network-information and upgrading to 4.13.0 helps Firebase realize that the network is connected, it still throws errors to the log and eventually re-connects. Every now and then, it will fail to realize there is a connection and will continue throwing errors to the log non-stop/

jiteshkaranjkar commented 6 years ago

I am getting this error "Could not reach Cloud Firestore backend. Backend didn't respond within 10 seconds" when running my Flutter application in Android Emulator. It was running a few minutes back. Not sure what the fix is. @mydoal I got the problem from the title but how can it be fixed.

jayordway commented 6 years ago

This is a serious issue and I am tempted to migrate from Firebase because of it, I have noticed that since the Firebase 5 release it has become more reoccurring, is there any hack or temporary solution?

I am not 100% sure what is causing the problem, but I do know that I can't recreate it with a test build that is easy to debug with chrome tools. It is only on a prod release.

The problem is exactly as described within the title description and there seems to be little I can do as a work around, this is not an issue with iOS and ionic 3.

sitaram-dev commented 5 years ago

image

please see https://firebase.google.com/support/release-notes/js

jayordway commented 5 years ago

I’m experiencing this with the Firebase Database not Firestore

sitaram-dev commented 5 years ago

@jayordway hi, i work on firestore as per my experience it is same 10 second issue, caused by slow bandwidth, [firestore offline data] automatically keep trying it to update data to back-end once gets the faster network. it happens with me many times but finally data gets updated in back-end. i hope this may help.

sitaram-dev commented 5 years ago

sometimes app or system uses proxy settings that scan every request hence make request execution late. to check if the request executing within 10 seconds in chrome go to Developer Tools->Nrtwork->All. then check the [time] field for every firebase request and then check [initiator] field to check who is initiating the request if initiator is not [firebase] then congratsss !!!! u got your culprit and just fix it

sitaram-dev commented 5 years ago

git1

sitaram-dev commented 5 years ago

git2

jimmykane commented 5 years ago

Hi I am experiencing the same issue but it's a tiny bit different.

I am uploading BLobs to firestore (small blobs of 10KB) and sometimes if that takes long what the firestore lib tries todo is merge those in 1request that passes the 10s limit of course and then the whole app becomes useless.

Why does firestore/firebase pack isolated write calls? I dont get this.

jimmykane commented 5 years ago

Here is an example:

On the same request: This is a document write

screenshot 2018-12-24 at 15 04 57

However it tries to add more data as the subcollections which I explicitly call in another promise and fire all with Promise all.

Looking further on the request I can see

screenshot 2018-12-24 at 15 05 11

WTF Should it have a on the same request the req1 data?

Graig123git commented 5 years ago

i am facing the same issue logs below

Firestore (5.8.1): Could not reach Cloud Firestore backend. Backend didn't respond within 10 seconds. This typically indicates that your device does not have a healthy Internet connection at the moment. The client will operate in offline mode until it is able to successfully connect to the backend.

however i deliberately turn off my internet connect. when my internet is connect the issue does not occur. I have the following code below

export const loadUserNotifications = () => async (dispatch) => {

// [START demo_initialize] // Fetch data from Firestore firebase.firestore().collection('cities').get() .then(documentSet => { // Print the ID and contents of each document documentSet.forEach(doc => { console.log(doc.id, ' => ', doc.data()); }); }) .catch(err => { // Error fetching documents alert(err) }); // [END demo_initialize]

}

My main problem is that while i am offline my catch block is not executed and the issue is throw. How can i catch this exception and ensure it does not crashes my app even when i am in offline mode.

Graig123git commented 5 years ago

my env is for react-native not angular.

hiepxanh commented 5 years ago

I have the same issue with:


firebase: 5.8.5
ionic: 4.1

I have no problem with android 6, but have problem with iOS. Event with debug or prod mode. the problem on iOS is: 1) the first, make a firestore request 2) then, out the app. come back 30 minutes later. Then make an other firestore request. This request never end, it doesn't raise any error too. I check network is fine. But it not showing up any new request.

how to debug to get more information for you? should I create new repository Ionic?

hiepxanh commented 5 years ago

@wti806 this can reproduce on iOS 10.0, i-Phone 6 sir. If you wait for 30 minutes. Can I help you anything to reproduce ? This bug is very important to our production app. The user on iOS, resume app then see that it not working. :(

hiepxanh commented 5 years ago

after few minute later, I see this when not closing app and let that request continue: image image

image

anyone save me?

var-const commented 5 years ago

@hiepxanh Thank you for your report. It sounds like you're experiencing a different issue. Can you please open a new issue in this repo? In the new issue, please provide detailed reproduction steps and, importantly, logs (to enable logs, use firebase.firestore.setLogLevel('debug')); when copying the logs, make sure you remove any info you might not want released publicly). Additionally, I have a couple of questions:

hiepxanh commented 5 years ago

does that mean that the app eventually reconnects? Or does the request still hang, even after you can see network activity in the web inspector?

I think the request still hang, event after I can see network activity in the web inspector I will open new issue for this. thank you sir.

MatthewPringle commented 5 years ago

Did you open a new issue, I am still seeing this now in Safari