firebase / firebase-admin-node

Firebase Admin Node.js SDK
https://firebase.google.com/docs/admin/setup
Apache License 2.0
1.63k stars 371 forks source link

Deadline Exceeded error! #349

Closed warlockdn closed 5 years ago

warlockdn commented 6 years ago

[REQUIRED] Step 2: Describe your environment

[REQUIRED] Step 3: Describe the problem

I am doing a basic Add to Firestore through Node Admin SDK. I just add a object to a document and then wait for the document ID to return after that I send it to the front end to be subscribed for realtime updates. But sometimes I receive the error while adding a document and also updating as to Deadline Exceeded

Steps to reproduce:

The code that I have added to my backend.

let ref = db.collection("orders");

return new Promise((resolve, reject) => {
            ref.add(order).then((order) => {
                logger.info(order);
                resolve(order);
            }).catch((err) => {
                logger.info(err);
                reject(err);
            })
})

There you go I receive errors at catch.

Also checked my account I don't see any high usage since it is in development phase so hardly adding 10-20 docs on a normal day.

Can you please help here. Thanks

google-oss-bot commented 6 years ago

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

schmidt-sebastian commented 6 years ago

Hi @warlockdn! Sorry to hear that you are having connection issues to Firestore. Note that the initial connection attempt can sometimes be slow, as there is a lot of overhead (Channel establishment, SSL handshakes, authentication). Once you have a connection to Cloud Firestore, the underlying channel will get re-used for further operations. You may be able to work around your issue if you start by issuing a DocumentReference.get() call. We retry those automatically if the connection establishment takes a bit longer than it should.

warlockdn commented 6 years ago

Hi @schmidt-sebastian sorry I don't quite understand. On application restart I already created a connection to firebase. But anyways can you guide me to a resource where I can see some demo or sample code as to why and how this can be used. ?

schmidt-sebastian commented 6 years ago

As said, this is not a solution, but rather a workaround:

const docRef = db.collection("orders").doc();
await docRef.get(); // This will retry on DEADLINE_EXCEEDED
// Now the channel is established.
docRef.create({...}):
warlockdn commented 6 years ago

Do u have a permanent solution to this ? I don't know if with this I can go into production ? If I have to wait to retry on things. Coz the point of being realtime will be of no use if on a load i receive these errors. Or may be i need to follow some other process ?

schmidt-sebastian commented 6 years ago

If you continue to run into these issues, then we should look at your network stack and how you connect to our data centers. If we do need to go down that route, we can let you know some environment variables that will help us debug.

warlockdn commented 6 years ago

Yea you can help me then lemme know what needs to be done so that I don't end up embarrassing my product haha. Thanks

schmidt-sebastian commented 6 years ago

Please set the following environment variables:

GRPC_TRACE=all GRPC_VERBOSITY=DEBUG

warlockdn commented 6 years ago

so this is the error I finally received

I0916 13:25:14.586417074   10852 completion_queue.cc:951]    RETURN_EVENT[0x23f6660]: QUEUE_TIMEOUT
I0916 13:25:14.591104089   10852 completion_queue.cc:851]    grpc_completion_queue_next(cq=0x23f6660, deadline=gpr_timespec { tv_sec: -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=(nil))
I0916 13:25:14.591189393   10852 completion_queue.cc:951]    RETURN_EVENT[0x23f6660]: QUEUE_TIMEOUT
I0916 13:25:14.591880859   10852 completion_queue.cc:851]    grpc_completion_queue_next(cq=0x23f6660, deadline=gpr_timespec { tv_sec: -9223372036854775808, tv_nsec: 0, clock_type: 0 }, reserved=(nil))
warlockdn commented 6 years ago

so do I need to initialise firebase connection on each function call or does it work once on initialising the server ?

warlockdn commented 6 years ago

??

schmidt-sebastian commented 6 years ago

Sorry, I am just catching up on my emails. You only need to initialize the client connection only once, and the network channel should stay open.

warlockdn commented 6 years ago

So what's the issue with the time out then ? My internet connectivity is pretty good

On Wed, Sep 19, 2018, 12:23 AM Sebastian Schmidt notifications@github.com wrote:

Sorry, I am just catching up on my emails. You only need to initialize the client connection only once, and the network channel should stay open.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/firebase/firebase-admin-node/issues/349#issuecomment-422506974, or mute the thread https://github.com/notifications/unsubscribe-auth/ADR8XkgdpookRGwgcuh3JlynA0OnFEDmks5ucUEygaJpZM4WYWqy .

schmidt-sebastian commented 6 years ago

Just to confirm, you are getting most of these errors on the initial document write and before you are using any other Firestore operations? I am suggesting that your initial operation should be a document read, which we will retry. The "time to first byte" from Firestore is not necessarily related to your network connection.

CapitanRedBeard commented 5 years ago

I get this as well. I have a collection with about 300k documents on it and simply calling .get() on that collection will result in the timeout. Its a firebase problem and not your local system.

I've seen this happen in hosted cloud functions, and the fix is to increase the timeout limit in the function details (max time is 540 seconds, default is 60 seconds). However in the node sdk I can't get figure out how to extends the default past the 60 second limit.

BrodaNoel commented 5 years ago

I'm dealing with the same issue. I reported it here: https://github.com/steadyequipment/node-firestore-backup/issues/48, due to it's actually this library who is throwing the error.

farhankhwaja commented 5 years ago

I am having the same issue, when try to read my collection which has 100k docs, it gives me DEADLINE ERROR message. How to solve this, even a simple read is so trouble some. Is there a way to export the data from the DB without hitting this Error

CapitanRedBeard commented 5 years ago

My workaround is to find a size that doesn't hit the DEADLINE ERROR, like 10k, then just loop by 10k increments and read for the database until you have read all your docs.

You can do something like this:

  const FOO_READ_LIMIT = 10000
  const foosRef = firestore.collection('foo');

  try {
    let isCalculating = true;
    let lastDoc = null;

    async.whilst(() => {
      return isCalculating;
    },
    async (next) => {
      const fooQuery = foosRef.limit(FOO_READ_LIMIT)
      const pagedFooQuery = 
        lastDoc 
          ? pagedFooQuery.startAfter(lastDoc)
          : pagedFooQuery

      const fooSnapshots = await pagedFooQuery.get();
      const size = fooSnapshots && fooSnapshots.size;

      if (size < FOO_READ_LIMIT) {
        isCalculating = false;
        next()
      }

      await doStuff(fooSnapshots);

      lastDoc = fooSnapshots.docs[FOO_READ_LIMIT - 1]
      next()
    },
    (error) => {
      console.log('All data is read');
    });
  } catch(e) {
    // Something wen wrong
  }
farhankhwaja commented 5 years ago

@CapitanRedBeard I ended doing something similar. But, thanks for the reply.

If the Firebase team can add an export option to the Firestore DB like RTDB has, it would help some folks here

jonrandahl commented 5 years ago

@CapitanRedBeard & @farhankhwaja while I don't know if this will help you, still I was running into the same Deadline exceeded errors with only less than 2k of records! I have implemented this into all of my cloud functions, hopefully, this will help you too:

/**
* Set timeout and memory allocation
* In some cases, your functions may have special requirements for a long timeout value or a large * allocation of memory.
*You can set these values either in the Google Cloud Console or in the function source code (Firebase only).
*/
const runtimeOpts = {
  timeoutSeconds: 540, // 9 minutes
  memory: '2GB'
}
/**
 * When a csv file is uploaded in the Storage bucket it is parsed automatically using
 * PapaParse.
 */
exports.covertToJSON = functions
  .runWith(runtimeOpts) // <== apply timeout and memory limit here!
  .storage
  .object()
  .onFinalize( object => {
[...]

Sadly I can't remember where I found that snippet but as I said, every little bit helps!

Jon

tallalj commented 5 years ago

So why is this happening? what is the limit that is being exceeded here? It is on blaze plan so this should not happen. Instead firebase should let us query as much as we want.. Kindly specify the technical issue that needs to be overcome to resolve this.

schmidt-sebastian commented 5 years ago

We currently configure a 60 second deadline for the RunQuery call (which both Query.get() and Query.stream() use). We believe that this should fit most use cases, and would like to refrain from increasing this deadline. Having a shorter deadline limits the amount of work that the backend does for clients that are no longer interested in a Querie's result, which generally results in fewer billed reads.

While somewhat convoluted, you can configure a different deadline for your client:

 const firestore = new Firestore({
      clientConfig: {
        interfaces: {
          'google.firestore.v1.Firestore': {
              methods: {
                RunQuery: {
                  timeout_millis: YOUR_NUMBER_HERE
                }
              }
            }
          }
        }
      });
npomfret commented 5 years ago

I'm getting these DEADLINE_EXCEEDED error when running tests using only very small sets of data (with "firebase-admin": "^7.0.0" / node v8.14.0). I'm also using the blaze plan so I don't think it's billing related. I'm not running inside a cloud function, it's just a regular node app.

It doesn't happen consistently either. I run small tests and it feels like 50% of the time my query times-out and runs into this error. The query itself returns a single record and should run in a fraction of a second.

Is it possible a contention issue? I have a number of parts to my app that may well be issuing queries and updates at the same time. It feels like something is deadlocked.

An example query that gets stuck in this way is:

        const collection = this._firestore.collection(Collections.OMS);
        const existingOpenOrders = await collection
            .where("accountId", "==", this._accountId)
            .where("exchangeId", "==", exchangeId)
            .where("type", "==", DocTypes.OPEN_ORDER)
            .get()

It returns between zero and maybe 4 records only.

I ran why-is-node-running at the point that it all locks up and got this, which doesn't mean much to me unfortunately.

schmidt-sebastian commented 5 years ago

Can you do two things for me:

Thanks!

npomfret commented 5 years ago

Hi - where can I find information about how to use setLogFunction? Sorry, have search but can't see it

hiranya911 commented 5 years ago

https://cloud.google.com/nodejs/docs/reference/firestore/0.8.x/Firestore#.setLogFunction

When using the Admin SDK:

admin.firestore.setLogFunction((log) => {
  console.log(log);
});
npomfret commented 5 years ago

Thanks. I'll add this, but the error isn't happening right now. I suspect it's something to do with my app. It's very "bursty" in terms of database updates. Possibly I was testing while a burst of writes was happening and that was blocking my local node process?

wilhuff commented 5 years ago

OK, if this does come back, let us know.

hesselbom commented 5 years ago

I just got this error suddenly when running database.doc('orders/1234').set(data, { merge: true }).

Just happened one time so far.

wilhuff commented 5 years ago

If you can come up with something that reproduces this or if you can capture logs while this is happening we'll be able to look at it.

Note that there was a connection pooling bug addressed as part of #499. That bug would manifest in circumstances where there were many long-lived listeners running in the application.

If you start seeing this more often, try the fix we there (a new release containing the fix is imminent).

rhyek commented 5 years ago

I'm getting this error a bit frequently. Stack trace on Sentry does not show where in my code this is happening. I'm assuming this is being emitted inside internals of firestore running in the background. Is there a way for me to determine what query is failing?

rhyek commented 5 years ago

I have a few endpoints on my api that are timing out and am getting a 502 from cloudflare, while having no idea what's causing this behavior. It sounds from what I read here is the queries are just never resolving and these deadline exceptions are happening in the background?

Here is a stack trace from one of the errors Sentry caught for me:

Error: 4 DEADLINE_EXCEEDED: Deadline Exceeded
  File "/build/node_modules/grpc/src/common.js", line 91, col 15, in Object.exports.createStatusError
    let error = new Error(message);
  File "/build/node_modules/grpc/src/client.js", line 233, col 26, in ClientReadableStream._emitStatusIfDone
    var error = common.createStatusError(status);
  File "/build/node_modules/grpc/src/client.js", line 211, col 8, in ClientReadableStream._receiveStatus
    this._emitStatusIfDone();
  File "/build/node_modules/grpc/src/client_interceptors.js", line 1272, col 15, in Object.onReceiveStatus
    emitter._receiveStatus(status);
  File "/build/node_modules/grpc/src/client_interceptors.js", line 568, col 42, in InterceptingListener._callNext
    return this.delegate[method_name](args_array[0], next_listener);
  File "/build/node_modules/grpc/src/client_interceptors.js", line 618, col 8, in InterceptingListener.onReceiveStatus
    this._callNext('onReceiveStatus', [status]);
  File "/build/node_modules/grpc/src/client_interceptors.js", line 1029, col 24, in null.<anonymous>
    first_listener.onReceiveStatus(response.status);

This is with 7.4.0.

rhyek commented 5 years ago

I should note that my node logs show the following. These don't immediately precede the above error. Sometimes they're hours apart:

(node:17) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 drain listeners added. Use emitter.setMaxListeners() to increase limit
schmidt-sebastian commented 5 years ago

@rhyek Regarding the MaxListenersExceededWarning. This should be addressed by the latest release of grpc-js. If you re-install your modules, you should automatically get 0.4.3 of @grpc/grpc-js. In versions prior to 0.4.1, these warnings showed up especially when it took longer than normal to establish a GRPC channel.

Sandeeprao69 commented 5 years ago

I am on blaze plan and I have about 90K documents and when i do admin.firestore().collection(collectionName).doc(id).collection('xxxx').get().then(()=> { //do something })

in my firebase function i get Error: Deadline exceeded Please not i am running my function with 2gb memory and 540 sec of timeout.

slinkstep commented 5 years ago

I am on blaze plan and I have about 90K documents and when i do admin.firestore().collection(collectionName).doc(id).collection('xxxx').get().then(()=> { //do something })

in my firebase function i get Error: Deadline exceeded Please not i am running my function with 2gb memory and 540 sec of timeout.

Having the same issue when it comes to read and iterate over large collections (+100 docs)

schmidt-sebastian commented 5 years ago

We are preparing a release of @google-cloud/firestore v2.3.0 that will increase the timeout for all of our operations to 60s. This applies to all operations issued by the SDK, and is independent of the timeout set by any runtime environment (such as GCF). We hope that this alleviates some of the issues you are encountering.

slinkstep commented 5 years ago

I started an issue with the error details and some code. I hope you can help me to find out a solution, since it's a critical feature for our project.

https://github.com/firebase/firebase-functions/issues/556

Thanks a lot. @schmidt-sebastian

Sandeeprao69 commented 5 years ago

Hi,

I was testing my app with about 180k records and i was trying to generate csv from json. since firebase query throw this error after 60k records what i did is break my operation into multiple steps.

I wrote a recursive function which paginate and fetched only 50k in each call.

First query will be like db.collection('XXX').doc('id').collection('xxx').orderBy("createdAt").limit(50000);

Second query will be like db.collection('XXXXX').doc('id').collection('XXXX').orderBy("createdAt").startAfter(lastRecord).limit(50000);

Please note createdAt was a field in my collection.

My firebase function took about 1.5 minute to complete this operation.

slinkstep commented 5 years ago

@schmidt-sebastian Still getting the same error after @google-cloud/firestore update to v2.3.0

schmidt-sebastian commented 5 years ago

@Sandeeprao69: Even with 60s, you will likely not be able to read 60,000 documents. Your options are to split the query up using cursors (as shown in your comment) or to increase the deadline manually to suit your needs:

 const firestore = new Firestore({
      clientConfig: {
        interfaces: {
          'google.firestore.v1.Firestore': {
              methods: {
                RunQuery: {
                  timeout_millis: YOUR_NUMBER_HERE
                }
              }
            }
          }
        }
      });
Sandeeprao69 commented 5 years ago

@Sandeeprao69: Even with 60s, you will likely not be able to read 60,000 documents. Your options are to split the query up using cursors (as shown in your comment) or to increase the deadline manually to suit your needs:

 const firestore = new Firestore({
      clientConfig: {
        interfaces: {
          'google.firestore.v1.Firestore': {
              methods: {
                RunQuery: {
                  timeout_millis: YOUR_NUMBER_HERE
                }
              }
            }
          }
        }
      });

I was able to fetch 60k records in less than 60s actually in firebase cloud function. I faced deadline exceeded error after 65k.

slinkstep commented 4 years ago

My workaround is to find a size that doesn't hit the DEADLINE ERROR, like 10k, then just loop by 10k increments and read for the database until you have read all your docs.

You can do something like this:

  const FOO_READ_LIMIT = 10000
  const foosRef = firestore.collection('foo');

  try {
    let isCalculating = true;
    let lastDoc = null;

    async.whilst(() => {
      return isCalculating;
    },
    async (next) => {
      const fooQuery = foosRef.limit(FOO_READ_LIMIT)
      const pagedFooQuery = 
        lastDoc 
          ? pagedFooQuery.startAfter(lastDoc)
          : pagedFooQuery

      const fooSnapshots = await pagedFooQuery.get();
      const size = fooSnapshots && fooSnapshots.size;

      if (size < FOO_READ_LIMIT) {
        isCalculating = false;
        next()
      }

      await doStuff(fooSnapshots);

      lastDoc = fooSnapshots.docs[FOO_READ_LIMIT - 1]
      next()
    },
    (error) => {
      console.log('All data is read');
    });
  } catch(e) {
  // Something wen wrong
  }

That is the best aproach I have found for getting thorugh this error

digvan commented 4 years ago

Still happening even with pagination

rhyek commented 4 years ago

Stopped using firebase a while ago and this bug is one the main reasons (there were a few others). Had a really rough week in production where we had to re-architect a bunch of backend stuff as quickly as possible due to this issue and it's still not resolved.

Very interesting product, otherwise.

schmidt-sebastian commented 4 years ago

We are tracking this internally via bug ID 139021175.

schmidt-sebastian commented 4 years ago

@digvan / @rhyek: Can you send timestamps and project ID to mrschmidt(at)google.com? Thanks!

digvan commented 4 years ago

@schmidt-sebastian, sent you an email.

magician11 commented 4 years ago
 const firestore = new Firestore({
      clientConfig: {
        interfaces: {
          'google.firestore.v1.Firestore': {
              methods: {
                RunQuery: {
                  timeout_millis: YOUR_NUMBER_HERE
                }
              }
            }
          }
        }
      });

I'm getting Error: 4 DEADLINE_EXCEEDED: Deadline exceeded

We're on the Blaze plan and I think we have something like 10000 records in a collection.

Seems like a possible solution is to increase the timeout value.

My code looks something like this..

    const snapshot = await admin
      .firestore()
      .collection('some-collection')
      .get();

Just not sure how to integrate the code snippet @schmidt-sebastian is suggesting into my code.

schmidt-sebastian commented 4 years ago

If you are using the Admin SDK, you can set is as follows:

const firestore = admin.firestore();
firestore.settings({clientConfig: ...});
await firestore.collection('...').get();