Extreme delay with functions and firestore on cold starts.

[itaydr]

Version info

firebase-functions:
"1.0.4"
firebase-tools:
Not using
firebase-admin:
"5.12.1"

Test case

I'm getting ~12 secs of cold start times, and about 50 ms when the function is warm.
I'm using this function to authenticate the users, which means it has to be a lot faster.

Here's a minified version of the code I'm using. I added the gist of what isEmailVerifiedWithAtleastOnePlace is doing, which is basically one call to firestore.

export default functions.https.onCall(
  async (data: CanSignInFuncParams, context) => {
    const email: string = data.email;

    if (!email) {
      console.error("No domain passed");
      return ResponseFactory.failureResponse("Missing parameter domain");
    } else {
      const isEmailVerified = await FirestoreService.isEmailVerifiedWithAtleastOnePlace(
        email
      );

      if (isEmailVerified.ok) {
        console.log(`Domain verification passed ${email}`);
        return ResponseFactory.successfullResponse();
      } else {
        const error = `Invalid domain ${email}`;
        console.error(new Error(error));
        return ResponseFactory.failureResponse(error, isEmailVerified.error);
      }
    }
  }
);

const isEmailVerifiedWithAtleastOnePlace = async (domain:string) => {
  const places = await admin 
      .firestore()
      .collection(FirestoreCollectionNames.Places)
      .where(FirestoreSharedKeys.Domain, "==", domain)
      .get();
}

Steps to reproduce

• Deploy the function, and call it.
• Don't use the function for a while and call it.

Were you able to successfully deploy your functions?

Yes

Expected behavior

Expecting the cold start not to take more than a few seconds. a difference of about 200X between cold start and warm start is unacceptable.

Actual behavior

Expecting the functions to return a lot quicker.

This isn't happening when I'm not using firestore/firebase-admin in my functions.

I read all the tips and tried almost anything I'm willing to try.

• I tried removing all other functions and deploying a project with only this function, which has only those two dependencies.
• Some people mentioned they hack it by keeping the function warm. I'm not willing to try this at the moment, and I would prefer to ditch google functions altogether if this is the case.
• My project is very small at the moment ~50 documents in firestore, and the functions aren't being called frequently (we're a seed staged startup). So cold starts are a huge issue for me.

I'm sure I'm not the only one experiencing this, and I think that a combination of firestore + cloud-functions is VERY common. Is there a clear vision for solving this?

Thanks for any help!

[laurenzlong]

Hey @itaydr thanks for filing, this is a known issue and we have made such improvements in the recent past such as this pull request: googleapis/nodejs-firestore#196. Unfortunately making Firestore cold starts faster is a difficult thing to do and it's going to take us some time to reduce the latency even more.

If it is an option for you, consider putting the user emails in the real time database instead. Initializing a real time database instance (i.e. admin.database()) is significantly faster on cold start.

[itaydressler]

The new node 8 environment makes things a bit faster.

[eleith]

@itaydressler what cold start costs are you seeing with loading firestore in your functions now?

I'm using node 8 and while I'm not seeing 12 seconds, I'm still seeing 5 to 9 seconds.

[eleith]

just to follow up, i've done some process.hrtime() logging and i'm not seeing large swaths of time being eaten up (now on node8 env) by firestore instantiation or importing dependencies / global variables. (less than 1-2 seconds).

[yuliankarapetkov]

You might want to try out this solution (at least temporarily): firebase/functions-samples/issues/170#issuecomment-323375462

[yoonjesung]

Tested with firebase/functions-samples/issues/170#issuecomment-323375462 and even with lazy loaded imports, caching in the global namespace, and importing only the functions used at runtime, cold starts still average around 10-15 seconds even with the most basic and lightweight functions (but as you point out, subsequent warm requests are good, in the 100-200 ms range).

My take on this currently is you either have to keep the function warm somehow with a cron job (by the way, this still wouldn't prevent cold starts on re-deployments unless a warmup request is sent immediately after deploy), or you're better off using a Compute Engine or App Engine Flex server.

Also interesting to note, App Engine Standard backend instances also have a very similar "cold start" time, so my guess is that functions are built off the same type of infrastructure?

[rchan]

Hey @laurenzlong is there any update to this in last 2 months? I'm experiencing the same issues, cold start times of around 8 to 10 seconds.

I've done all the optimisation suggestions such as lazy loading imports etc. I've also noticed that pure cloud function cold start has actually improved in past 6 months, especially when moving to Node 8. However, the point where you make the first call to Firestore, that's where the bulk of the delay sits. So a simple cloud function will cold start with acceptable delay, it is at the first call to Firestore that takes it up to 8 to 10s.

Have noticed that cold starts can happen after only 5 mins of no usage too.

Data size for the project is also very small at the moment, less than 20 docs and I'm fetching by id.
e.g.
const doc = await profilesRef.doc(userId).get()
if I console.log before and after that line, it clearly shows that's where all that 8 to 10s is

[kevinajian]

Thanks for the feedback. As Lauren mentioned, making Firestore cold starts faster is a difficult thing to do and will take time, so we appreciate your patience here.

That being said, is it possible to share your code? If there are a lot of operations in global scope then cold starts will be slower.

[rchan]

@kevinajian the only global scope items I have left are the Firebase ones

const functions = require('firebase-functions')
const admin = require('firebase-admin')
admin.initializeApp()
admin.firestore().settings({timestampsInSnapshots: true})

Those functions I have that don't use Firestore, they don't have this issue, cold starts are 2s max and mostly around 1s. Some of these even make API calls to other systems.

It's only the ones that uses Firestore has this problem and if I put console.log before and after the Firestore call, it clearly shows that's where most of the delay sits e.g.

console.log('begin')
const doc = await profilesRef.doc(userId).get()
console.log('end')

[thechenky]

@rchan thank you for doing all that investigating. I see you're measuring the first call to Firestore, which is not part of cold start but is part of the admin SDK. After profiling the Firestore calls, the average latency we're seeing is ~1s on the first call to get data. This latency will always be there on the first call because we need to establish a gRPC connection which necessarily takes some overhead to initialize. For completeness, we also tested out the latency for the Firestore module loading time, which was minuscule at ~30ms. Can you please confirm that you're using the latest firebase-functions SDK?

@itaydr and everyone else experiencing cold starts:
I'm glad to hear cold starts are better with Node 8, and would highly suggest switching to Node 8 if anyone is still experiencing delayed cold starts. To reduce cold start times even more you can move the admin import + initialization portions from the global scope into your function:

const functions = require('firebase-functions')

let is_f1_initialized = false

// using https.onRequest as example function here; can be any other function:
exports.f1 = functions.https.onRequest((req, res) => {
    const admin = require('firebase-admin')
    if (!is_f1_initialized) {
        admin.initializeApp()
        admin.firestore().settings({timestampsInSnapshots: true})
        is_f1_initialized = true
    }
    // the rest of the function
})

This is a good practice especially if you have many functions declared in your index.js and they all use different dependencies. Moving the dependencies closer into the function that will actually need it will reduce the cold starts for all your functions.

[yoonjesung]

@thechenky thanks for the additional clarifications as well as best practices.

Could you provide one additional clarification on the best practices? -- Does this lazy-loading of dependencies work even for function instances that have scaled down to 0 (due to low traffic)?

e.g. Function A and Function B are both declared in index.js; Function A receives continual moderate traffic while Function B only receives traffic periodically. Do both Function A and B share the same execution environment such that if B scales to 0, a new instance would be able to use the lazy-loaded globally cached variables declared in A?

[thechenky]

@yoonjesung even if the functions share the same file, they scale independently of each other. So in your example:

e.g. Function A and Function B are both declared in index.js; Function A receives continual moderate traffic while Function B only receives traffic periodically. Do both Function A and B share the same execution environment such that if B scales to 0, a new instance would be able to use the lazy-loaded globally cached variables declared in A?

Function A and B have different execution environments and do not share memory. So, function B cannot take advantage of the "already warm" global variables of function A. Hope this clarifies things.

[andrew-veresov]

@thechenky thank you for clarification

Firestore calls, the average latency we're seeing is ~1s on the first call to get data. This latency will always be there on the first call

The main issue here is not the time itself, but time limits of other services like actions on google. If a query execution exceeds a limit the actions on google just switches to the error flow. An error at the middle of a conversation might be OK. But an error at the beginning is almost a show stopper.

[madakk]

To reduce cold start times even more you can move the admin import + initialization portions from the global scope into your function

@thechenky if you don't mind clarifying this point a bit further, would there still be an advantage of doing this even if all declared functions will be importing admin and initializing firestore in the same manner?

We've seen a ~2 second improvement in cold start times of our cloud functions after moving to Node 8 as suggested, but we're still looking at ~5 seconds for functions which involve firestore operations. On the contrary, a simple cloud function which only involves admin functionality has a cold start of under 1 second.

[thechenky]

@madakk anything that executes in the global scope will add time to your cold starts, so yes, moving it into the scope of the function would decrease cold start times. However, it's important to note that cold starts will always be there since the infrastructure of scaling up and down your function basically has to stand up a new vm and initialize it for your function, which takes time.

This thread has grown to include other topics like slow calls to Firestore, time limits of executing function - let's keep it focused on cold starts here. Please see my guidance in #263 (comment) if you're having trouble with cold starts in general.

[thechenky]

I'm going to close this out - please follow the best practices outlined in #263 (comment) to reduce your cold start times. If you're experiencing any other problems, please open another issue.

[rchan]

@thechenky I don't believe the issue has been dealt with sufficiently.

The title of the issue is "Extreme delay with functions and firestore on cold starts"

The recommendation given is to lazy initialize, but me, @madakk and @eleith all reported separately that even with lazy initialization the initial firestore can take over 5s. I have tested this several times and can recreate each time.

Moving to node 8 and lazy initialization are good recommendations but does not help with the issue reported.

[thechenky]

I don't want to conflate several unrelated issues into this one, which deals only with cold starts (as original author posted). What you're describing is delay on first call to firestore, which is not a part of cold start. I have also benchmarked several times with the latest firebase-functions SDK and the longest I've seen is 1s delay for the first call to Firestore.

[rchan]

@thechenky the title of the issue clearly suggest it is "functions and firestore on cold starts", the example he gave clearly has no other dependencies other than firestore, he also states "I tried removing all other functions and deploying a project with only this function", these are all notes from the original issue

I would humbly suggest that focusing on pure cold starts, lazy initialising and moving to Node 8 are the things that are conflating several unrelated issues into one. The core of the issue is with Firestore.

[mbleigh]

As @thechenky mentioned "I have also benchmarked several times with the latest firebase-functions SDK and the longest I've seen is 1s delay for the first call to Firestore." -- we've been trying to reproduce this issue and we're not seeing the same kinds of delays when calling Firestore.

Does this issue still happen in Node 8, with latest firebase-functions and firebase-admin, on a single function? If someone who is experiencing this can create a minimum reproduction that consistently shows the delay (especially across multiple projects) that would help us a lot. As it is, we're not able to get the same result.

[rchan]

@mbleigh I've tested this again over the weekend and can confirm the first call to Firestore are now coming in mostly around 1 to 1.5 sec, with a worse case of 2.5 sec

It was the same code I tested a few weeks ago, with everything else the same, so either it has improved or there was a glitch that week

Happy to leave this as it for now.

Thanks

[leandrit1]

Hi @mbleigh and @laurenzlong , I am having a very similar issue to the guy above I believe.
The first function is done very fast, less than a second, I get the response "works", and the second time, after querying firestore, takes 6 seconds:
Function Version 1:

export const helloWorld = functions.https.onRequest(async (req, res) => {
  console.log(process.env.FUNCTION_NAME + ' has started');
  const admin = await import('firebase-admin');
  admin.initializeApp();
  res.status(200).json('works');
)}

Function Version 2, takes 6 seconds to return the user

export const helloWorld = functions.https.onRequest(async (req, res) => {
  console.log(process.env.FUNCTION_NAME + ' has started');
  const admin = await import('firebase-admin');
  admin.initializeApp();

  const userCol = await admin.firestore().collection('users').limit(1).get();
  const userDoc = userCol.docs[0];
  const user = userDoc.data();
  res.status(200).json(user);
)}

Dependencies:
"firebase": "^5.9.1",
"firebase-admin": "^7.1.1",
"firebase-functions": "^2.2.1",

[mbleigh]

This is due to googleapis/nodejs-firestore#528 and the dependence of the Firestore SDK on gRPC. You can read the discussion there for more context.

[MrAlek]

I don't know if anything more has surfaced on this issue but I am as well experiencing extreme delays on cold starts ranging from 4s to 16s(!), both on Firestore triggers and HTTP functions calling admin.firestore(), running on Node 8.

In our case, developing an application with a VOIP-component, this has an enormous impact as users are waiting in real time for these functions to fire for notifications to be sent. Is there anything in the works to address this issue?

Here's a function taking 16s to execute:

exports.addCreatedTimeA = functions
  .region('europe-west1')
  .firestore.document('{a}/{aId}')
  .onCreate(async (snapshot, context) => {
    return snapshot.ref.update({ createTime: snapshot.createTime })
  })

[GriffinJohnston]

Any updates on this front? Experiencing long delays (10s or more) with an extremely simple .set() inside a callable function.

[AmethystLiang]

We experience a 20 - 40 seconds delay with our first call to firestore using firebase-admin in cloud functions.

[jjalonso]

25 seconds here, onCreate trigger

[mbleigh]

There is ongoing discussion on this thread about the issue, please direct your comments there as this issue is closed.