Azure / Azure/azure-functions-host
Azure Functions on App Service Plan Servers Go Offline as Job is Running
- 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
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