Long running Azure WebJob fails - The client could not finish the operation within specified timeout

Question

I have a long running Azure WebJob (2-4h) which is consistently failing after around 90 minutes with a storage exception. I'm using the WebJobs 2.3.0 SDK and WindowsAzure.Storage 9.3.3.

[09/17/2019 05:14:23 > b0c2e2: ERR ] 
[09/17/2019 05:14:23 > b0c2e2: ERR ] Unhandled Exception: Microsoft.WindowsAzure.Storage.StorageException: The client could not finish the operation within specified timeout. ---> System.TimeoutException: The client could not finish the operation within specified timeout.
[09/17/2019 05:14:23 > b0c2e2: ERR ]    --- End of inner exception stack trace ---
[09/17/2019 05:14:23 > b0c2e2: ERR ]    at Microsoft.WindowsAzure.Storage.Core.Executor.Executor.EndExecuteAsync[T](IAsyncResult result) in c:\Program Files (x86)\Jenkins\workspace\release_dotnet_master\Lib\ClassLibraryCommon\Core\Executor\Executor.cs:line 51
[09/17/2019 05:14:23 > b0c2e2: ERR ]    at Microsoft.WindowsAzure.Storage.Queue.CloudQueue.EndExists(IAsyncResult asyncResult) in c:\Program Files (x86)\Jenkins\workspace\release_dotnet_master\Lib\ClassLibraryCommon\Queue\CloudQueue.cs:line 994
[09/17/2019 05:14:23 > b0c2e2: ERR ]    at Microsoft.WindowsAzure.Storage.Core.Util.AsyncExtensions.<>c__DisplayClass2`1.<CreateCallback>b__0(IAsyncResult ar) in c:\Program Files (x86)\Jenkins\workspace\release_dotnet_master\Lib\ClassLibraryCommon\Core\Util\AsyncExtensions.cs:line 69
[09/17/2019 05:14:23 > b0c2e2: ERR ] --- End of stack trace from previous location where exception was thrown ---
[09/17/2019 05:14:23 > b0c2e2: ERR ]    at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
[09/17/2019 05:14:23 > b0c2e2: ERR ]    at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
[09/17/2019 05:14:23 > b0c2e2: ERR ]    at Microsoft.Azure.WebJobs.Host.Queues.Listeners.QueueListener.<ExecuteAsync>d__25.MoveNext()
[09/17/2019 05:14:23 > b0c2e2: ERR ] --- End of stack trace from previous location where exception was thrown ---
[09/17/2019 05:14:23 > b0c2e2: ERR ]    at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
[09/17/2019 05:14:23 > b0c2e2: ERR ]    at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
[09/17/2019 05:14:23 > b0c2e2: ERR ]    at Microsoft.Azure.WebJobs.Host.Timers.TaskSeriesTimer.<RunAsync>d__14.MoveNext()
[09/17/2019 05:14:23 > b0c2e2: ERR ] --- End of stack trace from previous location where exception was thrown ---
[09/17/2019 05:14:23 > b0c2e2: ERR ]    at Microsoft.Azure.WebJobs.Host.Timers.WebJobsExceptionHandler.<>c__DisplayClass3_0.<OnUnhandledExceptionAsync>b__0()
[09/17/2019 05:14:23 > b0c2e2: ERR ]    at System.Threading.ThreadHelper.ThreadStart_Context(Object state)
[09/17/2019 05:14:23 > b0c2e2: ERR ]    at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
[09/17/2019 05:14:23 > b0c2e2: ERR ]    at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
[09/17/2019 05:14:23 > b0c2e2: ERR ]    at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
[09/17/2019 05:14:23 > b0c2e2: ERR ]    at System.Threading.ThreadHelper.ThreadStart()
[09/17/2019 05:14:23 > b0c2e2: SYS ERR ] Job failed due to exit code -532462766
[09/17/2019 05:14:23 > b0c2e2: SYS INFO] Process went down, waiting for 0 seconds
[09/17/2019 05:14:23 > b0c2e2: SYS INFO] Status changed to PendingRestart

The job is not doing anything with Azure Storage and from other questions I gather that this could be related to the WebJob writing log files to Azure Storage, and for this I have configured a custom StorageClientFactory with a long server timeout but this seems to make no difference.

Job configuration:

var config = new JobHostConfiguration()
config.Queues.MaxDequeueCount = 1; 
config.Queues.BatchSize = 1; 
ServicePointManager.DefaultConnectionLimit = int.MaxValue;
config.StorageClientFactory = new CustomStorageClientFactory();
var host = new JobHost(config);
host.RunAndBlock();



public class CustomStorageClientFactory : StorageClientFactory
{
    public override CloudBlobClient CreateCloudBlobClient(StorageClientFactoryContext context)
    {
        CloudBlobClient client = context.Account.CreateCloudBlobClient();
        client.DefaultRequestOptions.ServerTimeout = TimeSpan.FromHours(6);
        return client;
    }
}

Answer 1

This should be a by-design issue for Azure WebJob SDK 2.X. In the backend, it uses HttpWebRequest to access storage API.The problem is by default only 2 concurrent connections is allowed per server. So other async requests will timeout if the 2 http connections are occupied by other requests.

The workaround is setting DefaultConnectionLimit to bigger value like below:

static void Main(string[] args)
{
    // Set this immediately so that it's used by all requests.
    ServicePointManager.DefaultConnectionLimit = Int32.MaxValue;

    var host = new JobHost();
    host.RunAndBlock();
}

You can also simply upgrade Azure Web SDK to version 3.x which fixed this issue.

Refer to Managing concurrent connections and https://github.com/Azure/azure-webjobs-sdk/issues/755#issuecomment-319094679 for details.