Azure / Azure/azure-functions-host

Azure Functions on App Service Plan Servers Go Offline as Job is Running

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

Description

Azure Function Servers on App Service Plan go offline as job is executing. App service plan autoscale is enabled (scale to a specific instance count of 10) with no additional scale condition rules.

Even though the job starts with 10 servers, servers start to go offline as the job is executing. At one point, no servers are online. Only 1,000 tasks are being fed to the servers (not a heavy load at all). Eventually, server instance count returns to 10 after job is completed.

I only found three exceptions in App Insights, which I've listed below, I can't figure out which is causing the servers to go offline.

Timeout (176 ocurrences):
```
Timeout value of 00:01:30 was exceeded by function: Functions.PageCrawler
InvocationId | 9b9b1ed7-1805-4f43-b58c-db344541abff
--
Microsoft.Azure.WebJobs.Host.FunctionTimeoutException:
at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor+d__27.MoveNext (Microsoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35Microsoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.csMicrosoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: 634)
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor+d__25.MoveNext (Microsoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35Microsoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.csMicrosoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: 547)
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor+d__24.MoveNext (Microsoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35Microsoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.csMicrosoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: 503)
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor+d__23.MoveNext (Microsoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35Microsoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.csMicrosoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: 439)
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor+d__17.MoveNext (Microsoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35Microsoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.csMicrosoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: 249)
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor+d__17.MoveNext (Microsoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35Microsoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.csMicrosoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: 293)
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor+d__14.MoveNext (Microsoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35Microsoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.csMicrosoft.Azure.WebJobs.Host, Version=3.0.4.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: 89)
```

MessageLockLost (18 ocurrences):
```
The lock supplied is invalid. Either the lock expired, or the message has already been removed from the queue. Reference:4ee072fd-d04c-428e-a3b9-0fe839592184, TrackingId:2cedb6e8-e718-4f31-abf2-cb6ed9ce92cd_B2, SystemTracker:crawlpagebus:queue:taskqueue~159, Timestamp:2019-02-10T18:26:43
--
Microsoft.Azure.ServiceBus.MessageLockLostException:
at Microsoft.Azure.ServiceBus.Core.MessageReceiver+d__94.MoveNext (Microsoft.Azure.ServiceBus, Version=3.0.2.0, Culture=neutral, PublicKeyToken=7e34167dcc6d6d8c)
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at Microsoft.Azure.ServiceBus.Core.MessageReceiver+<>c__DisplayClass75_0+<b__0>d.MoveNext (Microsoft.Azure.ServiceBus, Version=3.0.2.0, Culture=neutral, PublicKeyToken=7e34167dcc6d6d8c)
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at Microsoft.Azure.ServiceBus.RetryPolicy+d__18.MoveNext (Microsoft.Azure.ServiceBus, Version=3.0.2.0, Culture=neutral, PublicKeyToken=7e34167dcc6d6d8c)
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at Microsoft.Azure.ServiceBus.RetryPolicy+d__18.MoveNext (Microsoft.Azure.ServiceBus, Version=3.0.2.0, Culture=neutral, PublicKeyToken=7e34167dcc6d6d8c)
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at Microsoft.Azure.ServiceBus.Core.MessageReceiver+d__75.MoveNext (Microsoft.Azure.ServiceBus, Version=3.0.2.0, Culture=neutral, PublicKeyToken=7e34167dcc6d6d8c)
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at Microsoft.Azure.ServiceBus.Core.MessageReceiver+d__74.MoveNext (Microsoft.Azure.ServiceBus, Version=3.0.2.0, Culture=neutral, PublicKeyToken=7e34167dcc6d6d8c)
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at Microsoft.Azure.ServiceBus.MessageReceivePump+d__17.MoveNext (Microsoft.Azure.ServiceBus, Version=3.0.2.0, Culture=neutral, PublicKeyToken=7e34167dcc6d6d8c)
```

Operation Canceled (7 ocurrences);
```
System.Threading.CancellationToken.ThrowOperationCanceledException
--
System.OperationCanceledException:
at System.Threading.CancellationToken.ThrowOperationCanceledException (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Threading.SemaphoreSlim+d__33.MoveNext (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at Microsoft.Azure.ServiceBus.MessageReceivePump+d__11.MoveNext (Microsoft.Azure.ServiceBus, Version=3.0.2.0, Culture=neutral, PublicKeyToken=7e34167dcc6d6d8c)
```
#### Investigative information

Please provide the following:

- Timestamp: 2019-02-11T15:44:35.051Z
- Function App version (1.0 or 2.0): 2.0
- Function App name: crawlpage
- Function name(s) (as appropriate): PageCrawler
- Invocation ID: 73b3ad55-9195-4285-9ec0-afb817e22d79
- Region: us-east

#### Repro steps

1. Deploy to Azure Functions
2. Enable auto scale, set "Scale to a specific instance count" to 10
3. Wait for 10 server instances to come online
4. Start Feeding tasks through BusService
5. Watch live metrics as server count goes from 10 down to 0.

#### Expected behavior

If autoscale is set to 10 and enabled, all 10 servers should stay online as the job is executing.

#### Actual behavior

Servers start getting knocked off as the job is executing. It starts with 10, at one point, no servers are running. Once the job is complete, then it returns to an instance count of 10.

#### Known workarounds

N/A

#### Related information

Provide any related information:
- Python RunTime
- Using BusService Queue Trigger to feed tasks into Azure functions
- Since it's an app service plan, I had to create a Private Docker Image and deploy it (followed these [docs](https://docs.microsoft.com/en-us/azure/azure-functions/functions-create-function-linux-custom-image))
- Running on S1 App Service plan, but tried it on P3V2 App Service Plan and it behaved the same way ... servers were still going offline
- Results are being returned correctly (ie. function itself does work) ... just don't understand why the servers are going offline
- Timeout in `host.json` file set to 1 minute and 30 seconds
- Azure Function was written on Ubuntu 16.04 Machine
- Activity Log inside of App Service Plan doesn't show [any strange behaviour](https://imgur.com/a/pKGVjMr)

Contributor guide

Open the contributing guide

Research direction

Start with the reproduction steps and the FunctionExecutor, MessageReceiver, and MessageReceivePump stack frames shown in the report. Reproduce the Python queue-triggered workload on an App Service Plan with autoscale fixed at 10, then correlate instance changes with the timeout, lock-loss, and cancellation errors. Done means the cause is identified and the ten instances remain available during execution.

Written by the indexing model from the issue text.

Assessment

Tech stack
azure, docker, python
Domain
backend, cloud
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
25/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.