firebase / firebase-js-sdk

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

Payload too large error causes firebase realtime database client to freeze / never return or resolve promise #4219

Closed akhaya closed 1 year ago

akhaya commented 3 years ago

[READ] Step 1: Are you in the right place?

Yes

[REQUIRED] Step 2: Describe your environment

[REQUIRED] Step 3: Describe the problem

Upon calling someRef.once('value'), firebase-admin client gets stuck in a loop disconnecting/reconnecting and reattempting the same query after encountering the following error: FIREBASE INTERNAL ERROR: Server Error: The specified payload is too large, please request a location with less data.

Even if the original request to the server is cancelled, the client continues to reconnect and log that internal error, causing all future requests to that same server to stall as well, since the client is unable to perform any other read/write operations after it has encountered this error.

We tried await in a try/catch block, as well as using then/catch and in either case the promise was not resolving or throwing an error. It was just stuck on the line of code calling .once('value').

Expected behavior:

Client should throw an error when this happens, allowing the server to handle it in a catch block, and allowing the server to continue using the client for any further queries.

Steps to reproduce:

  1. Attempt to query a payload that is over the payload limit. (In our case, we were accidentally querying the entire realtime database by passing undefined to db.ref() - see relevant code)
  2. See the logs fill up with the repeated FIREBASE INTERNAL ERROR: Server Error: The specified payload is too large, please request a location with less data.
  3. Try to use the client again while the server is still running (maybe with another request to the server) - nothing will happen and client continues to log the internal error.

Relevant Code:

Simplified example of code:

const express = require('express');
const admin = require('firebase-admin');
const firebaseApp = admin.initializeApp({
  credential: admin.credential.cert(keyObject),
  databaseURL: url
}, '*******');

admin.database.enableLogging(true);

const db = firebaseApp.database();
const app = express();

app.get('/some-path', async (req, res) => {
  try {
    const data = (await db.ref(undefined).once('value')).val(); // This will end up querying the whole realtime DB, triggering the payload too large error. Request gets stuck here.

    res.json({
      success: true,
      data
    });
  } catch(e) {
    res.json({
      success: false,
      error: e.message
    })
  }
});

Logs

[2020-12-16T16:19:42.160Z]  @firebase/database: p:0: Browser went online.
[2020-12-16T16:19:42.165Z]  @firebase/database: p:0: Listen called for / default
[2020-12-16T16:19:42.167Z]  @firebase/database: p:0: Making a connection attempt
[2020-12-16T16:19:42.389Z]  @firebase/database: p:0: Auth token refreshed
[2020-12-16T16:19:42.392Z]  @firebase/database: getToken() completed. Creating connection.
[2020-12-16T16:19:42.393Z]  @firebase/database: c:0:0: Connection created
[2020-12-16T16:19:42.394Z]  @firebase/database: c:0:0:0 Websocket connecting to wss://*********************/.ws?v=5
[2020-12-16T16:19:42.643Z]  @firebase/database: c:0:0:0 Websocket connected.
[2020-12-16T16:19:42.647Z]  @firebase/database: c:0:0: Realtime connection established.
[2020-12-16T16:19:42.648Z]  @firebase/database: p:0: connection ready
[2020-12-16T16:19:42.649Z]  @firebase/database: p:0: reportStats {"c":{"sdk.node.9-4-2":1}}
[2020-12-16T16:19:42.649Z]  @firebase/database: p:0: {"r":1,"a":"s","b":{"c":{"sdk.node.9-4-2":1}}}
[2020-12-16T16:19:42.652Z]  @firebase/database: p:0: {"r":2,"a":"gauth","b":{"cred":"*******************"}}
[2020-12-16T16:19:42.652Z]  @firebase/database: p:0: Listen on / for default
[2020-12-16T16:19:42.653Z]  @firebase/database: p:0: {"r":3,"a":"q","b":{"p":"/","h":""}}
[2020-12-16T16:19:42.704Z]  @firebase/database: p:0: from server: {"r":1,"b":{"s":"ok","d":""}}
[2020-12-16T16:19:42.794Z]  @firebase/database: c:0:0: Primary connection is healthy.
[2020-12-16T16:19:42.794Z]  @firebase/database: p:0: from server: {"r":2,"b":{"s":"ok","d":{"auth":null,"expires":1608139182}}}
[2020-12-16T16:20:59.307Z]  @firebase/database: FIREBASE INTERNAL ERROR: Server Error: The specified payload is too large, please request a location with less data.
[2020-12-16T16:20:59.310Z]  @firebase/database: c:0:0:0 Websocket connection was disconnected.
[2020-12-16T16:20:59.310Z]  @firebase/database: c:0:0:0 WebSocket is closing itself
[2020-12-16T16:20:59.311Z]  @firebase/database: c:0:0: Realtime connection lost.
[2020-12-16T16:20:59.311Z]  @firebase/database: c:0:0: Closing realtime connection.
[2020-12-16T16:20:59.311Z]  @firebase/database: c:0:0: Shutting down all connections
[2020-12-16T16:20:59.311Z]  @firebase/database: p:0: data client disconnected
[2020-12-16T16:20:59.311Z]  @firebase/database: p:0: Trying to reconnect in 0ms
[2020-12-16T16:20:59.312Z]  @firebase/database: 0: onDisconnectEvents
[2020-12-16T16:20:59.314Z]  @firebase/database: p:0: Making a connection attempt
[2020-12-16T16:20:59.314Z]  @firebase/database: getToken() completed. Creating connection.
[2020-12-16T16:20:59.314Z]  @firebase/database: c:0:1: Connection created
[2020-12-16T16:20:59.315Z]  @firebase/database: c:0:1:0 Websocket connecting to wss://**************************
[2020-12-16T16:20:59.506Z]  @firebase/database: c:0:1:0 Websocket connected.
[2020-12-16T16:20:59.507Z]  @firebase/database: c:0:1: Realtime connection established.
[2020-12-16T16:20:59.507Z]  @firebase/database: p:0: connection ready
[2020-12-16T16:20:59.507Z]  @firebase/database: p:0: {"r":4,"a":"gauth","b":{"cred":"**************************"}}
[2020-12-16T16:20:59.508Z]  @firebase/database: p:0: Listen on / for default
[2020-12-16T16:20:59.508Z]  @firebase/database: p:0: {"r":5,"a":"q","b":{"p":"/","h":""}}
[2020-12-16T16:20:59.649Z]  @firebase/database: p:0: from server: {"r":4,"b":{"s":"ok","d":{"auth":null,"expires":1608139259}}}
[2020-12-16T16:20:59.650Z]  @firebase/database: FIREBASE INTERNAL ERROR: Server Error: The specified payload is too large, please request a location with less data.
[2020-12-16T16:20:59.652Z]  @firebase/database: c:0:1:0 Websocket connection was disconnected.
[2020-12-16T16:20:59.652Z]  @firebase/database: c:0:1:0 WebSocket is closing itself
[2020-12-16T16:20:59.652Z]  @firebase/database: c:0:1: Realtime connection lost.
[2020-12-16T16:20:59.653Z]  @firebase/database: c:0:1: Closing realtime connection.
[2020-12-16T16:20:59.653Z]  @firebase/database: c:0:1: Shutting down all connections
[2020-12-16T16:20:59.653Z]  @firebase/database: p:0: data client disconnected
[2020-12-16T16:20:59.656Z]  @firebase/database: p:0: Trying to reconnect in 204.51904254475855ms
[2020-12-16T16:20:59.656Z]  @firebase/database: 0: onDisconnectEvents
[2020-12-16T16:20:59.865Z]  @firebase/database: p:0: Making a connection attempt
[2020-12-16T16:20:59.866Z]  @firebase/database: getToken() completed. Creating connection.
[2020-12-16T16:20:59.866Z]  @firebase/database: c:0:2: Connection created
[2020-12-16T16:20:59.868Z]  @firebase/database: c:0:2:0 Websocket connecting to wss://**************************
[2020-12-16T16:21:00.054Z]  @firebase/database: c:0:2:0 Websocket connected.
[2020-12-16T16:21:00.054Z]  @firebase/database: c:0:2: Realtime connection established.
[2020-12-16T16:21:00.055Z]  @firebase/database: p:0: connection ready
[2020-12-16T16:21:00.056Z]  @firebase/database: p:0: {"r":6,"a":"gauth","b":{"cred":"**************************"}}
[2020-12-16T16:21:00.056Z]  @firebase/database: p:0: Listen on / for default
[2020-12-16T16:21:00.057Z]  @firebase/database: p:0: {"r":7,"a":"q","b":{"p":"/","h":""}}
[2020-12-16T16:21:00.169Z]  @firebase/database: p:0: from server: {"r":6,"b":{"s":"ok","d":{"auth":null,"expires":1608139260}}}
[2020-12-16T16:21:00.171Z]  @firebase/database: FIREBASE INTERNAL ERROR: Server Error: The specified payload is too large, please request a location with less data.
[2020-12-16T16:21:00.172Z]  @firebase/database: c:0:2:0 Websocket connection was disconnected.
[2020-12-16T16:21:00.172Z]  @firebase/database: c:0:2:0 WebSocket is closing itself
[2020-12-16T16:21:00.173Z]  @firebase/database: c:0:2: Realtime connection lost.
[2020-12-16T16:21:00.173Z]  @firebase/database: c:0:2: Closing realtime connection.
[2020-12-16T16:21:00.173Z]  @firebase/database: c:0:2: Shutting down all connections
[2020-12-16T16:21:00.173Z]  @firebase/database: p:0: data client disconnected
[2020-12-16T16:21:00.173Z]  @firebase/database: p:0: Trying to reconnect in 1058.385778767387ms
[2020-12-16T16:21:00.173Z]  @firebase/database: 0: onDisconnectEvents
[2020-12-16T16:21:01.235Z]  @firebase/database: p:0: Making a connection attempt
[2020-12-16T16:21:01.236Z]  @firebase/database: getToken() completed. Creating connection.
[2020-12-16T16:21:01.236Z]  @firebase/database: c:0:3: Connection created
[2020-12-16T16:21:01.237Z]  @firebase/database: c:0:3:0 Websocket connecting to wss://****************************************
[2020-12-16T16:21:01.461Z]  @firebase/database: c:0:3:0 Websocket connected.
[2020-12-16T16:21:01.461Z]  @firebase/database: c:0:3: Realtime connection established.
[2020-12-16T16:21:01.462Z]  @firebase/database: p:0: connection ready
[2020-12-16T16:21:01.462Z]  @firebase/database: p:0: {"r":8,"a":"gauth","b":{"cred":"**************************"}}
[2020-12-16T16:21:01.463Z]  @firebase/database: p:0: Listen on / for default
[2020-12-16T16:21:01.463Z]  @firebase/database: p:0: {"r":9,"a":"q","b":{"p":"/","h":""}}
[2020-12-16T16:21:01.575Z]  @firebase/database: p:0: from server: {"r":8,"b":{"s":"ok","d":{"auth":null,"expires":1608139261}}}
[2020-12-16T16:21:01.582Z]  @firebase/database: FIREBASE INTERNAL ERROR: Server Error: The specified payload is too large, please request a location with less data.
[2020-12-16T16:21:01.582Z]  @firebase/database: c:0:3:0 Websocket connection was disconnected.
[2020-12-16T16:21:01.583Z]  @firebase/database: c:0:3:0 WebSocket is closing itself
[2020-12-16T16:21:01.583Z]  @firebase/database: c:0:3: Realtime connection lost.
[2020-12-16T16:21:01.583Z]  @firebase/database: c:0:3: Closing realtime connection.
[2020-12-16T16:21:01.583Z]  @firebase/database: c:0:3: Shutting down all connections
[2020-12-16T16:21:01.583Z]  @firebase/database: p:0: data client disconnected
[2020-12-16T16:21:01.583Z]  @firebase/database: p:0: Trying to reconnect in 4.978922839410453ms
[2020-12-16T16:21:01.584Z]  @firebase/database: 0: onDisconnectEvents
[2020-12-16T16:21:01.587Z]  @firebase/database: p:0: Making a connection attempt
[2020-12-16T16:21:01.588Z]  @firebase/database: getToken() completed. Creating connection.
[2020-12-16T16:21:01.588Z]  @firebase/database: c:0:4: Connection created
[2020-12-16T16:21:01.589Z]  @firebase/database: c:0:4:0 Websocket connecting to wss://****************************************
[2020-12-16T16:21:01.828Z]  @firebase/database: c:0:4:0 Websocket connected.
[2020-12-16T16:21:01.830Z]  @firebase/database: c:0:4: Realtime connection established.
[2020-12-16T16:21:01.831Z]  @firebase/database: p:0: connection ready
[2020-12-16T16:21:01.831Z]  @firebase/database: p:0: {"r":10,"a":"gauth","b":{"cred":"**************************"}}
[2020-12-16T16:21:01.832Z]  @firebase/database: p:0: Listen on / for default
[2020-12-16T16:21:01.833Z]  @firebase/database: p:0: {"r":11,"a":"q","b":{"p":"/","h":""}}
[2020-12-16T16:21:02.499Z]  @firebase/database: p:0: from server: {"r":10,"b":{"s":"ok","d":{"auth":null,"expires":1608139262}}}
[2020-12-16T16:21:02.500Z]  @firebase/database: FIREBASE INTERNAL ERROR: Server Error: The specified payload is too large, please request a location with less data.
[2020-12-16T16:21:02.501Z]  @firebase/database: c:0:4:0 Websocket connection was disconnected.
[2020-12-16T16:21:02.501Z]  @firebase/database: c:0:4:0 WebSocket is closing itself
[2020-12-16T16:21:02.502Z]  @firebase/database: c:0:4: Realtime connection lost.
[2020-12-16T16:21:02.502Z]  @firebase/database: c:0:4: Closing realtime connection.
[2020-12-16T16:21:02.502Z]  @firebase/database: c:0:4: Shutting down all connections
[2020-12-16T16:21:02.502Z]  @firebase/database: p:0: data client disconnected
[2020-12-16T16:21:02.502Z]  @firebase/database: p:0: Trying to reconnect in 748.2789057753995ms
[2020-12-16T16:21:02.502Z]  @firebase/database: 0: onDisconnectEvents

The above logs repeated continuously until 2020-12-16T16:40:03.420Z

Possibly Related Issues

https://github.com/firebase/firebase-admin-node/issues/1036 https://stackoverflow.com/questions/52911753/firebase-gets-stuck-when-reading-too-much-data

google-oss-bot commented 3 years ago

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

hiranya911 commented 3 years ago

Transferring to the JS SDK repo since this seems to be an issue with the @firebase/database package that implements the RTDB API.

google-oss-bot commented 3 years ago

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

akhaya commented 3 years ago

Just checking in to see if there is an update around this?

luskin commented 3 years ago

We are seeing this as well on our end and having difficulty pinpointing where it's occurring in our system

SolomonLake commented 3 years ago

We are also experiencing this issue in our production environment! The sdk appears to retry for an indefinite amount of time.

The workaround we landed on was implementing 30 second a Promise.race timeout, after which point we can continue executing our process and/or terminate the ref connection.

Please correct the retry implementation, making the error properly surface to the ref .once('value') promise, so that we can stop relying on a timeout and guesswork!

filipesilva commented 3 years ago

I also saw this today, with both .on and .once. At first I thought this happened due to the 256mb RTDB limit on reads applying to both .once (unsurprising) and .on (surprising). But I don't think this is true because I'm pretty sure that on our codebase we've loaded way more than 256mb with .once and .on.

I think it has to do with the size of individual paths though. We usually load a path called that contains objects with a roughly 20kb string, in the order of up to 1k objects on this path, hundreds of thousands of time a day, for more than a year now. But this time the strings were ~600kb instead, one of each of ~1000 objects. This was the first time we saw the error.

Our path looks something like below, and we query ordering by t:

{
  "logs": {
    "-MW-LUEQ13LfrxK5Bm_i": {
      "t": 1,
      "tx": "string here"
    },
    "-MW-LujwGVl-_VRXAUHv": {
      "t": 2,
      "tx": "string here"
    },
    "-MW-LuMF2qnWDrtpz8NH": {
      "t": 3,
      "tx": "string here"
    },
    "-MW-LutO1gGbb0mCf6B_": {
      "t": 4,
      "tx": "string here"
    },
    "-MW-LuVjbIi0oDuptQSo": {
      "t": 5,
      "tx": "string here"
    },
    "-MW-Lv5YYpUlvQM11_dM": {
      "t": 6,
      "tx": "string here"
    }
  }
}
alectrocute commented 3 years ago

We experienced this today and are actively seeking a workaround.

BigBalli commented 2 years ago

You will need to chunk your request. I created a script to do so in order to backup the entire node. You can adapt as needed: https://bigballi.com/blog/how-to-backup-firebase-realtime-database

google-oss-bot commented 1 year ago

Hey @akhaya. We need more information to resolve this issue but there hasn't been an update in 5 weekdays. I'm marking the issue as stale and if there are no new updates in the next 5 days I will close it automatically.

If you have more information that will help us get to the bottom of this, just add a comment!

google-oss-bot commented 1 year ago

Since there haven't been any recent updates here, I am going to close this issue.

@akhaya if you're still experiencing this problem and want to continue the discussion just leave a comment here and we are happy to re-open this.