firebase-admin-node: Realtime db triggers timeout after upgrading admin sdk to 9.6.0

[REQUIRED] Describe your environment

  • Operating System version: GCF
  • Firebase SDK version: 8.4.1
  • Firebase Product: database, functions
  • Node.js version: 10
  • NPM version: 7.7.6

[REQUIRED] Describe the problem

After upgrading to firebase-admin 9.6.0 realtime database triggers timeout periodically. Downgrade to 9.5.0 solved the issues.

Steps to reproduce:

Write a realtime db trigger. Use root reference to realtime db provided by the trigger (change.after.ref.root) to access data (read or write). Do not initialize firebase admin (this maybe irrelevant). The function will work correctly for a number of invocations. Eventually, one of the invocations will lead to the function timing out with whatever timeout value is configured for that specific function (60 seconds by default).

Relevant Code:

The code is proprietary, but even the simplest code that reads data from a different location than triggered will exhibit this behavior.

return change.after.ref.root
        .child(`some/db/path`)
        .once('value').then(() => return true) // this will never resolve or fail

I wish I could attach a screenshot of the functions Health tab showing spike in latencies after the update. Reverting to 9.5.0 eliminated timeouts.

About this issue

  • Original URL
  • State: closed
  • Created 3 years ago
  • Reactions: 4
  • Comments: 17 (7 by maintainers)

Most upvoted comments

I believe I have isolated the issue with RTDB calls periodically timing out. This happens when the metadata server sends a token that have a TTL shorter than 5 minutes (which seems to happen every 30 minutes or so in Cloud Functions). Here’s an example sequence of events leading to the problem:

  • 2:46:18.567 PM: SDK initializes database (admin.database()) and registers the token refresh event to 25 minutes (TTL - 5 minutes)
  • 3:11:19.350 PM: Token refresh event fires, but the metadata server sends back the same token now with a TTL less than 5 minutes

The 2nd step above triggers the following event handler: https://github.com/firebase/firebase-admin-node/blob/011c53043896587e2d41228b3c8fdc463faff56a/src/database/database-internal.ts#L118-L120

That in turns calls the following logic: https://github.com/firebase/firebase-admin-node/blob/011c53043896587e2d41228b3c8fdc463faff56a/src/firebase-app.ts#L69-L72

But since the last fetched token has a short TTL, it causes the SDK to attempt a token refresh again. This results a in a tight loop, with separate RPCs for each refresh attempt, and can result in a timeout in some cases. The loop continues until the metadata server eventually sends a fresh token with a TTL longer than 5 minutes.

I have a fix in progress.