AppCheck token refresh is triggering `permission-denied` in existing Firestore snapshot listeners

[harrisonlo]

Describe your environment

• Operating System version: macOS Monterey 12.6.3
• Browser version: Chrome 110
• Firebase SDK version: 9.17.2
• Firebase Product: AppCheck, Firestore

Describe the problem

When the browser tab is left open for an extended period of time, the app regularly detects permission-denied errors from Firestore snapshot listeners. Here is a screenshot in which you may see a pattern:

These errors mostly have a 55 minutes interval, which I suspect is due to the token refresh from AppCheck, which I recently enforced. There are 5~7 active snapshot listeners in the app, not all of them trigger this all the time. As you can see in the screenshot, only a pair of them consistently did. However, all of them erroneously triggered the error at one point.

Depending on the app logic, it sometimes breaks the app. i.e. when you don't have permission, you can't access a document.

Also I should clarify, the user does have permission. Refreshing always solves the permission issue.

Steps to reproduce:

Enforce Firestore AppCheck in the Firebase console, then open a page with a Firestore listener for 55 minutes to an hour until the AppCheck token refreshes.

Relevant Code:

This error is captured in the third argument of the Firestore onSnapshot hook.

const unsubscribe = onSnapshot(
    query(...),
    snapshot => {...},
    error => capture(error)
)

[google-oss-bot]

I couldn't figure out how to label this issue, so I've labeled it for a human to triage. Hang tight.

[dwyfrequency]

@harrisonlo - Can you confirm the Token time to live in the firebase console for this project? Did you change this value from the default to be 1 hour?

[harrisonlo]

@dwyfrequency The app is using reCAPTCHA Enterprise and yes it is indeed 1 hour. I don't remember changing this, but should I change it to 1 day?

[harrisonlo]

Here is a new set of error logs:

At 20:12, all 5 snapshot listeners trigger the error. Then you can see the 55 minutes intervals. The snapshot pair at row 6 & 7 is also part of the first 5, so the interval there is about 16 minutes only.

Interestingly, here are the console logs from the browser:

2023-03-13T12:12:20.723Z translates to Mar 13, 2023, 8:12:20 PM my time. This is when the errors start to show. I suspect it was the moment I opened my laptop and the internet was unavailable for ~2 seconds.

[hsubox76]

So if I'm understanding correctly, the computer was asleep (closed) for a while, and when you opened it, you saw these console logs, and nothing before it (from while the computer was asleep)?

The reason I'm asking is that a fetch-network-error doesn't trigger the 1 day throttle, only a fetch-status-error does:

firebase-js-sdk/packages/app-check/src/providers.ts

Line 84 in a57f435

(e as FirebaseError).code?.includes(AppCheckError.FETCH_STATUS_ERROR)

. The initial throttle error message, when the throttling begins, looks exactly like the yellow warnings but it should be an error. Do you see any error like that before this?

The only thing that should trigger the throttle should be a 403 or 404 error, which means it would have to be connected to the internet, reach the App Check endpoint, and get one of those errors in response. One guess is that this happened while the computer was asleep, and reCAPTCHA fails somehow if the computer is closed, which causes a 403 error when the SDK tries to exchange the reCAPTCHA token with the App Check endpoint, which causes you to be locked out for a day.

Do all these examples occur when the computer is closed, or asleep? Or does it also happen when the computer is open and active the whole time?

Edit: Also, did you ever see any errors that say "ReCAPTCHA error."?

[hsubox76]

May be same issue as #6708

[hsubox76]

Possible solution:

We currently only clear the throttle if there's a successful request:

firebase-js-sdk/packages/app-check/src/providers.ts

Line 100 in a57f435

// If successful, clear throttle data.

Instead, maybe we should clear it if there's any other error other than a FETCH_STATUS_ERROR (right before line 97) - or clear it if it's a set of specific errors (including FETCH_NETWORK_ERROR).

[harrisonlo]

Update: the errors went away after setting the token time to live to 1 day. I don't know if the underlying issue is solved tho. Back when I created this issue, the errors happened during usage, not when the computer is closed. I also don't remember seeing any ReCAPTCHA error.