Azure / azure-functions-host

The host/runtime that powers Azure Functions
https://functions.azure.com
MIT License
1.92k stars 441 forks source link

Cold start taking a long time in Consumption mode for c# azure function #838

Closed lemkepf closed 5 years ago

lemkepf commented 7 years ago

This is our first use of Azure Functions and we are happy with the idea so far. We have a couple functions setup that will get hit randomly throughout the day so it will never be called warmed up. The issue that we are having is the cold startup time is 30s+.

Here is an example: Monitor logs says that function was only 2,640ms running time. On our end we saw 30.30 seconds. This request happened 18:34 on Thursday, October 27, 2016 (UTC).

If we call it again right after the first it's a 200ms response time. If we wait 10 minutes it'll take another 30+seconds again.

I've created a dummy app name if you want to look into this: dumm2345

Is this 30 second startup time expected?

davidebbo commented 7 years ago

Thanks for the info, we will investigate. Request was from RestSharp, right?

lemkepf commented 7 years ago

Yup. One solution we are starting with right now is to have a timer function run every 30 seconds. It literally does nothing but keeps the service alive and waiting for our random web calls. It's a terrible solution, but it's a hack we can live with for now.

davidebbo commented 7 years ago

Is it ok to discuss function names here as long as we keep the Web App name private (which is the host name)?

lemkepf commented 7 years ago

Yup. Go for it.

davidebbo commented 7 years ago

So initial finding is that I see the following sequence of requests:

  1. 18:36:08: Requests for / coming from ReadyForRequest/1.0. Takes 26.5 seconds
  2. 18:36:09: Requests for / coming from ReadyForRequest/1.0. Takes 1.3 seconds
  3. 18:36:11: Request for /api/CreateZipLink from RestSharp/105.2.3.0. Takes 29.4 seconds.
  4. 18:36:15: Request for /api/GetZipFile/[guid] from Chrome. Takes 3.9 seconds and returns a large response (1MB)

Though probably the first one is the relevant one that kicks in the cold start and that we need to understand.

lemkepf commented 7 years ago

Yup: 18:36:11: Request for /api/CreateZipLink from RestSharp/105.2.3.0. Takes 29.4 seconds. That's the one that we care about. All it does is put a document into documentdb. But I'm pretty sure it's the cold start that's the issue. Thanks for looking into this!

lindydonna commented 7 years ago

Assigning to @davidebbo for an update

davidebbo commented 7 years ago

We have done a number of optimizations, and you should be seeing better cold start time than before. We're still working on additional optimizations that will make it yet faster.

jenyayel commented 7 years ago

We have a similar problem with cold start.

We have an Azure Function used as a webhook for Slash Comman on Slack. One of the requirments of the command is that response must be served within 3000ms. Every time that command used after sometime of inactivity there is a timeout.

You can check the source code here. I tried to strip out everything from it, but the plain response.

Is there only way to keep function "warm" in Consumption Plan? Is pinging it with some scheduler OK?

mjgpy3 commented 7 years ago

@davidebbo do these optimizations have implications for .NET functions a a whole? (We're using F# azure functions)

davidebbo commented 7 years ago

They apply to all function apps. Previously, there would be occasional 30s+ cold starts even for a trivial Function (see first entry in issue). Now those peaks have been eliminated, and the cold start is typically 4 to 10s in the trivial case.

jenyayel commented 7 years ago

Do you have plans on improving it below 4s?

davidebbo commented 7 years ago

Yes, see my earlier comment: We're still working on additional optimizations that will make it yet faster. No ETA at this point, but active work is happening now.

DavidBrower commented 7 years ago

I have just created my first Azure function in order to compare it to AWS lambda. All the function does is return a random entry from a static List<string> that contains around 100 elements. When calling the function with a 'cold start' it sometime takes around 35 secs to respond. Subsequent requests take about 0.2 seconds.

My concern is that one of the reasons for exploring serverless functions is to avoid paying for the times that the function isn't being called. Having to periodically call the function in order to avoid cold starts seems to defeat that purpose.

davidebbo commented 7 years ago

@DavidBrower 35s does not sound right, as the current expectation is 4s to 10s (aside from the large npm tree issue). Can you share the name of your app and the time when you saw such timing?

DavidBrower commented 7 years ago

@davidebbo the name of the function is:

https://functionsa7b1a72e.azurewebsites.net/api/ObliqueStrategiesV3.

Really, most of the time when I haven't called the function for about 5 minutes I then get the delayed response. I'm simply calling:

curl -sk https://functionsa7b1a72e.azurewebsites.net/api/ObliqueStrategiesV3 from my desktop.

davidebbo commented 7 years ago

@DavidBrower it really helps to get the UTC time of one such incident, so we are looking at the same thing. I looked at all requests to that function today (i.e. 1/31 UTC) and the longest it took was 7s.

DavidBrower commented 7 years ago

Interestingly, I have not had the very long response times since the weekend. I'm down to 5-6 secs for my cold starts.

I've checked the Azure Functions Invocation Log and I'm afraid that it doesn't seem to keep the invocations for more than a day ago. The best I can do is to say that the first of the long response times started around 16:00 30th January UTC. Sorry that I can't give you exact times. I have been running my tests using curl so I don't have an audit trail of function calls.

davidebbo commented 7 years ago

Ok, that's good news. Let's keep observing, and let us know if you hit some extreme slow starts again.

DavidBrower commented 7 years ago

Thanks @davidebbo

DavidBrower commented 7 years ago

$ time os
Mechanicalise something idiosyncratic real 0m13.450s user 0m0.105s sys 0m0.652s

Just received 13.45 secs with a cold start at 3 February 18:35 UTC. os is just the alias I am using in Bash to call my Azure function.

sjwaight commented 7 years ago

Going to chime in here and say that slow start-up, even for simple C# Functions is impacting key functionality we are using them for. We're on standard consumption plans with Always On switched on, but still see substantial ramp-up on initial invocation after some period (I assume 5 minutes). I've resorted to putting a timer triggered app in to our App Service just to try and keep it all warm and toasty.

DavidBrower commented 7 years ago

@sjwaight have you found that then increases your costs on Azure?

davidebbo commented 7 years ago

@sjwaight what do you mean by 'standard consumption plans'? There is Consumption, and App Service Plan (which includes Standard), so the two term are mutually exclusive.

Note that I'd like to focus this thread on the issue in Consumption mode. Outside of Consumption, with Always On, it should always stay hot. If it doesn't for someone, let's open a separate issue an investigate why Always On is not working.

anoff commented 7 years ago

89663 ms cold start at 2017-07-02 9:55 UTC for a GET on https://cbtraindev.azurewebsites.net/api/bert which is a node function with HTTP triggers & storage input. Around 2017-07-02 11:35 it took 120464 ms to get a response. Pure execution time according to the functions monitor was 117,492 ms

Consecutive warm runs are mostly ~100ms sometimes going near 1000ms which is all good.

Are there lately any issues with coldstart perf compared to the previous comments?

LTsLlama commented 7 years ago

We have the same issue, some cold starts take 20s and we require <1s. I logged a feature request to add the always on option to consumption plans: https://feedback.azure.com/forums/355860-azure-functions/suggestions/31332643-allow-always-on-mode-on-the-consumtion-plan

touseefbsb commented 7 years ago

everyone should vote the feature request @DL-LiveTiles made it will benefit all of us :)

ricklove commented 6 years ago

Is it still suggested to have a 5min timer to keep things warm?

And when doing so it it enough to just have the timer, or is it needed to make an http request to keep web triggers warm?

davidebbo commented 6 years ago

We have optimizations that are partially deployed, and should be fully deployed in the next month. They take the cold start down to about 2 seconds. You can try it right now in the West US 2 region.

kchanlee commented 6 years ago

I have the same issue. I have a testing Function App in consumption plan in south central US. I setup a bi-hourly ping and it takes ~30 seconds to response.

anoff commented 6 years ago

I know this thread is about c# but I ended up here with my javascript app as well. So for anyone having issues on JS: Using the https://github.com/Azure/azure-functions-pack on JS significantly helps!

khalid-halo commented 6 years ago

Has anyone figured out any solutions other than recurring calls? Will switching to non-consumption plan help?

LTsLlama commented 6 years ago

@khalid-halo Using the non-consumption plan with always on turned on is a solution.

0xacf commented 6 years ago

It seems the amount of time necessary to wait for a response to an HTTP function invocation is often a lot longer than what shows up in the Azure portal logs. Cold start times seem to be under 2 seconds in the logs, but some HTTP requests take > 12 seconds to receive a response. This is on the v2 pre-release.

davidebbo commented 6 years ago

@0xacf you are correct that the time shows in the logs does not include the cold start of the Function runtime.

Also, note that the cold start optimization mentioned above (which uses warm 'placeholder' sites) is currently only for v1, so your v2 Preview app does not benefit from it. We will bring this optimization to v2 as it gets closer to become GA (sorry, no clear ETA yet).

ricklove commented 6 years ago

@davidebbo Just to confirm:

By "warm placeholder sites... only for v1", are you saying that using a 5 minute trigger to keep a function server warm will not work with v2 yet?

0xacf commented 6 years ago

Ah, interesting. Even the logs show up to a 1.7 second execution time for the first invocation of a function after a long period of time. Subsequent executions take ~30ms. This function accesses Azure table storage, but creates a new storage client on each invocation. A function which does nothing except return a string literal exhibits similar behaviour, but only seems to get up to about 300ms in the logs.

davidebbo commented 6 years ago

@ricklove no, that would work as well, as that keeps an instance alive. What I'm referring to is the case where you don't currently have any running instance, and one needs to be started. That's when placeholder comes into play to avoid paying for a full cold start.

0xacf commented 6 years ago

Out of curiosity, have you considered adding an "always on" feature for the consumption plan, obviously with some surcharge? It seems like you can achieve a similar effect with a 5 minute trigger, but that also seems a much less clean solution. Also, using the "5 minute trigger" method, is there a guarantee that no function invocations will cause a cold start? For example, could a second instance be created for scaling, causing a 2 second latency for one request?

Perhaps it's just my use case, but even 2 seconds seems like an unusably long latency for an API request.

davidebbo commented 6 years ago

@0xacf There have been talks of potential hybrid mode between App Service plan and Consumption. You'd have some dedicated VMs, but if it needs to scale beyond that for some requests bursts, it would move into Consumption mode. But this is just an idea at this point.

And yes, with the timer, you only warm up one instance.

ricklove commented 6 years ago

@davidebbo Sorry, I'm not familiar with the placeholder you mentioned and I didn't find it in the comments above.

What is a "placeholder"? How do you achieve that and what effect will it have for v2 once ready?

davidebbo commented 6 years ago

@ricklove placeholders is an internal optimization that works as follows:

You don't need to do anything special to use it. It just makes cold start faster, but only for v1 at this point. Once it becomes available for v2, it will start helping without you needing to change anything.

0xacf commented 6 years ago

For what it's worth, my personal preference would be purchasing capacity at the sandbox rather than the VM level. I would happily pay the $0.000016/GB-s rate or some multiple of it continuously to eliminate this cold start time, and have additional sandbox instances created in advance of when their capacity is required. I think this latency by itself prevents Functions from being useful for a large segment of applications (ie, anything that needs to respond in less than 2 seconds). Using dedicated VMs for low latency is a solution, but it kind of undermines one of the key benefits of the serverless paradigm (fine-grained scaling).

Just some thoughts. Thanks for the information, and the optimizations!

LTsLlama commented 6 years ago

I agree with @0xacf, We want a simple server less solution that allow us flexibility and low start-up times without having to even worry about how it work at the cost implications of different tiers. Adding a always on setting per function will be the perfect solution for us.

davidebbo commented 6 years ago

Thanks for the feedback. We'll have to see what we can achieve. Definitely, scenario where 2 seconds is not good enough are tough right now. For context, see how this issue started, and it was 30 seconds at the time. So some progress was made :)

zeeshanejaz commented 6 years ago

Looking forward to the hybrid approach between consumption and app-service plans.

marcofalconi commented 6 years ago

I am having the same issue with slow cold starts which led me to set up a function to call two other functions, time response time, and notify me if either function takes longer than five seconds to respond (I wasn't sure if the warm-up needed to occur per-function or per-function app). I started with triggering this "health check" to be called every five minutes and eventually turned it down to three, but I can still experience hours and hours with cold-start times of 10+ seconds on every single request. The only input binding on the slow function is to Azure Table Storage, which returns a single row. Can a function still "go cold" when called every three minutes? Do functions needs to be "warmed up" at the function level or at the function app level? By the way, I implemented this function app in the portal thinking that I could prototype there and get an idea of performance before implementing as a precompiled function in source control from VS.

romandres commented 6 years ago

@davidebbo We use C# precompiled functions and function proxies that we are deploying using ARM and VSTS. We were nowhere near the 2s cold start response time with a simple function. For instance, making a request to a function proxy using an unknown route took the proxy about 17-18s to respond with 404.

I did some testing and found out that disabling PHP on a function app added about 12-14s to the cold start response time. Setting PHP to v5.6 improved the cold start performance considerably. We disabled PHP in our ARM templates because we do not use it and will turn it back on now.

davidebbo commented 6 years ago

@romandres indeed, there is a known issue that hurts the cold start when PHP is removed. Note that this PHP setting is actually meaningless for Function Apps, so there is no harm in leaving it the way it is by default. We will work to address the issue, but for now just remove all traces of that setting from your templates.

romandres commented 6 years ago

@davidebbo Good to know, thanks. Are there any other settings that are known to impact the cold start performance at the moment?

EDIT: I'm asking because still there are some seconds in the response times that I cannot account for. I started to make some tests without Application Insights (removed the app setting) and that seemed to have an impact of a few seconds. One app cold starts about 6-7s slower with App Insights enabled.