CODEWITHSUNDEEP
azureazure-functions
Sumit Garg
Sumit Garg

Reputation: 453

Azure Function is calling itself twice on App service plan

I have the following code in my azure function with 10 minutes manual timeout.

using System.Net;

public static async Task<HttpResponseMessage> Run(HttpRequestMessage req, TraceWriter log)
{
    log.Info("C# HTTP trigger function processed a request.");
    try
    {
        TimeSpan ts = TimeSpan.FromMinutes(1);
        for(int i=0;i<10;i++)
        {
            await Task.Delay(ts);
            log.Info(String.Format("After 1 Min Delay {0}",i));
        }
        log.Info(String.Format("After 10 Min Delay "));
        return req.CreateResponse(HttpStatusCode.OK);
    }
    catch (Exception e)
    {
        log.Info(String.Format("exception: {0}", e));
        return req.CreateResponse(HttpStatusCode.BadRequest);
    }
}

when I run the above function in Azure, I see the function creates a new instance after 3 minutes. (check the below log) 

2018-05-15T11:12:42  Welcome, you are now connected to log-streaming service.
2018-05-15T11:12:55.826 [Info] Function started (Id=f25e0bbd-7103-4823-b8f1-ef28888f7007)
2018-05-15T11:12:55.826 [Info] C# HTTP trigger function processed a request.
2018-05-15T11:13:55.844 [Info] After 1 Min Delay 0
2018-05-15T11:14:55.857 [Info] After 1 Min Delay 1
2018-05-15T11:15:55.862 [Info] After 1 Min Delay 2
2018-05-15T11:16:47.385 [Info] Function started (Id=7371ed94-9b62-40cc-bec0-00b8d5e0a250)
2018-05-15T11:16:47.385 [Info] C# HTTP trigger function processed a request.
2018-05-15T11:16:55.879 [Info] After 1 Min Delay 3
2018-05-15T11:17:47.395 [Info] After 1 Min Delay 0
2018-05-15T11:17:55.883 [Info] After 1 Min Delay 4
2018-05-15T11:18:47.400 [Info] After 1 Min Delay 1
2018-05-15T11:18:55.899 [Info] After 1 Min Delay 5
2018-05-15T11:19:47.411 [Info] After 1 Min Delay 2
2018-05-15T11:19:55.914 [Info] After 1 Min Delay 6
2018-05-15T11:20:47.413 [Info] After 1 Min Delay 3
2018-05-15T11:20:55.920 [Info] After 1 Min Delay 7
2018-05-15T11:21:47.416 [Info] After 1 Min Delay 4
2018-05-15T11:21:55.930 [Info] After 1 Min Delay 8
2018-05-15T11:22:47.436 [Info] After 1 Min Delay 5
2018-05-15T11:22:55.936 [Info] After 1 Min Delay 9
2018-05-15T11:22:55.936 [Info] After 10 Min Delay
2018-05-15T11:22:55.936 [Info] Function completed (Success, Id=f25e0bbd-7103-4823-b8f1-ef28888f7007, Duration=600105ms)
2018-05-15T11:23:47.447 [Info] After 1 Min Delay 6
2018-05-15T11:24:47.452 [Info] After 1 Min Delay 7
2018-05-15T11:25:47.467 [Info] After 1 Min Delay 8
2018-05-15T11:26:47.478 [Info] After 1 Min Delay 9
2018-05-15T11:26:47.478 [Info] After 10 Min Delay
2018-05-15T11:26:47.478 [Info] Function completed (Success, Id=7371ed94-9b62-40cc-bec0-00b8d5e0a250, Duration=600086ms)

In above log, you can see that azure function is calling twice and also it gives the error (500: internal server error) and after it completes its execution.

Upvotes: 3

Views: 3929

Answers (2)

Jerry Liu
Jerry Liu

Reputation: 17790

It is about http request timeout and retry.

When I run the function directly in portal, it will be called again after nearly 4m like @Sumit and @Joey have seen. I decrease the Delay to 10s, and the function is only triggered once and returns 200.

Try to use postman to post request, this time the function is triggered only once with response message below.

enter image description here

As we can see in the code, no response sent back until 10m process finished. It is beyond the timeout setting and it seems by design that request posted by portal will be retried after timeout.

Update

Azure function is one kind of Azure Web App, see Azure Web App time out 230s setting.

There is a 230 second (i.e. a little less than 4 mins) timeout for requests that are not sending any data back. After that, the client gets the 500 you saw, even though in reality the request is allowed to continue server side

Upvotes: 3

Joey Cai
Joey Cai

Reputation: 20067

I reproduce your problem and found that it seems to be an issue.

the fix is now deployed in version 1.0.11015.0 (visible in the 'Settings' page of the Functions portal). If you are not running this version, manually restart your app and it will pick up the latest version.

Also, as you have said, you use the app service plan. You could run longer than the maximum execution time allowed on the Consumption plan (of 10 minutes).

Upvotes: 0

Related Questions