Azure / Azure/azure-functions-host

Scale Controller starting too many instances causing multiple cold start delays

Open
#4,859 3 comments 1 reaction 0 assignees View on GitHub
Dominant language
C#
Stars
2k
Forks
482
Avg merge
2d 12h
Merged PRs (30d)
38

Description

#### Investigative information

Please provide the following:

- Timestamp: 8/29/2019, 7:35:00 AM (EST)
- Function App version (1.0 or 2.0): 2.0
- Function name(s) (as appropriate): Ping, Level1, Level2, Level3, KeepAlive
- Invocation ID: See below.
- Region: Central US

#### Repro steps

Provide the steps required to reproduce the problem:

1. Load the FunctionAppReproColdStartIssue solution from the following repro application: https://github.com/SimonLuckenuik/azure-repro-samples/tree/master/FunctionAppReproColdStartIssue
2. Publish the project FunctionAppReproColdStartIssue inside a normal Consumption Plan Function App with an associated application insight resource
3. Update the "host" variable URL of Program.cs inside project ConsoleAppTestFunction to reflect your newly deployed Function App
4. Go inside Application Insights for that new Function App and reach the Live Metrics Stream section. Wait until you can see KeepAlive logs inside the server instance running.
5. Start the project ConsoleAppTestFunction

FunctionAppReproColdStartIssue Function App contains the following:
- Ping: GET HttpTrigger returning the WEBSITE_INSTANCE_ID of the instance executing the GET
- Level3: GET HttpTrigger returning the WEBSITE_INSTANCE_ID of the instance executing the GET prefixed with L3
- Level2: GET HttpTrigger that calls Level3 API endpoint with HttpClient and then returning the WEBSITE_INSTANCE_ID of the instance executing the GET prefixed with L2, concatenated with Level3 output.
- Level1: GET HttpTrigger that calls Level2 API endpoint with HttpClient and then returning the WEBSITE_INSTANCE_ID of the instance executing the GET prefixed with L1, concatenated with Level2 output.
- KeepAlive: TimerTrigger running every minute.

ConsoleAppTestFunction Console App is calling concurrently Ping, Level1, Level2 at regular interval, logging inside the console the response (concatenated WEBSITE_INSTANCE_IDs)

This app represents an issue we are facing with an internal app. One of the third party library we are using is requiring configuration through and HTTP endpoint, which the Function App provides.
We have one customer facing API (eg Level1) which is using the 3rd party component which in turns call the internal API (Level2). One the customer hits the Level1 API, we are sometime hit by a double cold start causing long delays for the public API.

#### Expected behavior

Provide a description of the expected behavior.
- After step 4, in Live Metrics Stream you see a single Function App Instance, initial cold start delay because of timer.
- After step 5, in Live Metrics Stream you see a single Function App Instance (no cold start on HTTP GETs)

#### Actual behavior (as seen for Invocation state above)

Provide a description of the actual behavior observed.
- After step 4, in Live Metrics Stream you see a single Function App Instance
- After step 5, 3 additionnal instances are running (total of 4 instances). One for the timer, 3 for the HTTP requests (looks like one per "level" of API). The new instances seem to be started as soon Level1 calls Level2.

- Instance running Timer before step 5:
- WEBSITE_INSTANCE_ID 77ea59c24ef19cbd5bb2fc844969d830dd901f9b434a2fd8768513e7fb2fa59a

- Instances running after starting ConsoleAppTestFunction (started after step 5):
- WEBSITE_INSTANCE_ID 0e61d4b29262aa3ad2e6c45187f7a1e5582c4704217387c9dff52d201191d58f
- WEBSITE_INSTANCE_ID e114761183d1d4b3ded9570732da1190e6cf6a2be68009a472e5420fc44487ca
- WEBSITE_INSTANCE_ID 13e18d819a879e30527533784da46f112c5018695648380d8f1669e7dcb14f02

Cold starts Invocation Ids:
- 89b9725f-b11e-4c26-af66-59cb43cd4c66:
- Function: KeepAlive
- When: 8/29/2019, 6:50:27 AM
- WEBSITE_INSTANCE_ID: 77ea59c24ef19cbd5bb2fc844969d830dd901f9b434a2fd8768513e7fb2fa59a
- App Insights OperationId: eb23902cad8cff408b7e1f5b791d9411)
- 037a7273-f299-4ab9-9b9d-2958162fafa8:
- Function: Level3
- When: 8/29/2019, 7:35:00 AM
- WEBSITE_INSTANCE_ID 13e18d819a879e30527533784da46f112c5018695648380d8f1669e7dcb14f02
- App Insights OperationId: c75408b384550c45a33a6ed6236f6391)
- afbc5153-3db4-4f77-924b-7c9ea81845ef:
- Function: Level1
- When: 8/29/2019, 7:35:00 AM
- WEBSITE_INSTANCE_ID e114761183d1d4b3ded9570732da1190e6cf6a2be68009a472e5420fc44487ca
- App Insights OperationId: 28e97a0642cc2845a32c184ddcc6a167)
- 2b719d7d-624f-44f7-8845-0dcb675dd97c:
- Function: Ping
- When: 8/29/2019, 7:35:00 AM
- WEBSITE_INSTANCE_ID 0e61d4b29262aa3ad2e6c45187f7a1e5582c4704217387c9dff52d201191d58f
- App Insights OperationId: 51ca254156dbd8469f3a960c2b3cddcb)

#### Known workarounds

None found.
We tried using WEBSITE_MAX_DYNAMIC_APPLICATION_SCALE_OUT=1 to prevent the scaling since this is a low volume API, it would have been appropriate, however the scale happens anyway.

#### Related information

Provide any related information

* Programming language used : C#
* Links to source: https://github.com/SimonLuckenuik/azure-repro-samples/tree/master/FunctionAppReproColdStartIssue
* Bindings used: HttpTrigger, TimerTrigger

Contributor guide

Open the contributing guide

Research direction

Run the linked FunctionAppReproColdStartIssue reproduction, starting with Program.cs in ConsoleAppTestFunction and the Ping, Level1, Level2, Level3, and KeepAlive triggers. Compare Live Metrics Stream instance IDs with the expected single-instance behavior and test whether WEBSITE_MAX_DYNAMIC_APPLICATION_SCALE_OUT=1 is honored during nested HTTP calls.

Written by the indexing model from the issue text.

Assessment

Tech stack
azure, csharp
Domain
cloud, infrastructure
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.