Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Syncing function triggers by calling the functions runtime site failed #10078

Open
kirk-marple opened this issue Apr 29, 2024 · 7 comments
Open

Comments

@kirk-marple
Copy link

kirk-marple commented Apr 29, 2024

Check for a solution in the Azure portal

I just noticed an error in two of our Function Apps today, and both in DEV and PROD.

In the Azure Portal, it's showing "Runtime version: Error", and says:
We were not able to load some functions in the list due to errors. Refresh the page to try again. See details

Clicking 'see details' gives:
image

It appears to be a problem syncing the web app triggers.

Strange thing, a different Function App, both in DEV and PROD, is fine and shows all the functions.

At this point, I have no idea what to investigate further. The APIs in the Function Apps seem to be up and running, but I'm concerned that they may stop working at some point.

The problem Function Apps load fine locally, and lists out all available functions.

I don't remember seeing this issue before, and looking at the last month, I'm not seeing any other errors in the Activity Log about this (prior to today), except for one on Apr 14.

I tried restarting the function apps, redeploying code, etc. and nothing changed the behavior. Also, this started out of the blue, and wasn't related to a recent new code deployment.

Expected behavior

Sync triggers to work correctly, and not give Forbidden or InternalServerError.

Actual behavior

Provide a description of the actual behavior observed.

Kudu logs shows:

This XML file does not appear to have any style information associated with it. The document tree is shown below.
<step title="BackgroundTrace" date="2024-04-25T17:41:19.307" instance="13aed7" url="synctriggers-operation" method="POST">
<step title="Updating shutdown sentinel last write time" date="2024-04-25T17:41:19.323" SemaphoreCount="6"/>
<!--  duration: 16ms  -->
<step title="Delaying '00:01:00' for Functions site to restart." date="2024-04-25T17:41:19.354"/>
<!--  duration: 16ms  -->
<step title="Begin HttpPost https://redacted-functions.azurewebsites.net/admin/host/synctriggers, x-ms-request-id: 2442b05a-458d-407f-a36f-ee2b2e660d76" date="2024-04-25T17:42:19.436"/>
<!--  duration: 31ms  -->
<step title="End HttpPost, status: InternalServerError" date="2024-04-25T17:42:19.748"/>
<!--  duration: 31ms  -->
<step title="Begin HttpPost https://redacted-functions.azurewebsites.net/admin/host/synctriggers, x-ms-request-id: 2442b05a-458d-407f-a36f-ee2b2e660d76" date="2024-04-25T17:42:20.814"/>
<!--  duration: 16ms  -->
<step title="End HttpPost, status: InternalServerError" date="2024-04-25T17:42:20.908"/>
<!--  duration: 16ms  -->
<step title="Begin HttpPost https://redacted-functions.azurewebsites.net/admin/host/synctriggers, x-ms-request-id: 2442b05a-458d-407f-a36f-ee2b2e660d76" date="2024-04-25T17:42:21.958"/>
<!--  duration: 16ms  -->
<step title="End HttpPost, status: InternalServerError" date="2024-04-25T17:42:22.039"/>
<!--  duration: 32ms  -->
<step title="Syncing function triggers by calling the functions runtime site failed. System.Net.Http.HttpRequestException: Response status code does not indicate success: 500 (Internal Server Error). at System.Net.Http.HttpResponseMessage.EnsureSuccessStatusCode() at Kudu.Core.Helpers.PostDeploymentHelper.<PostAsync>d__49.MoveNext() in C:\Kudu Files\Private\src\master\Kudu.Core\Helpers\PostDeploymentHelper.cs:line 720 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Kudu.Core.Helpers.PostDeploymentHelper.<>c__DisplayClass38_1.<<TryFunctionsRuntimeSyncTriggers>b__1>d.MoveNext() in C:\Kudu Files\Private\src\master\Kudu.Core\Helpers\PostDeploymentHelper.cs:line 299 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Kudu.Core.Infrastructure.OperationManager.<>c__DisplayClass4_0.<<AttemptAsync>b__0>d.MoveNext() in C:\Kudu Files\Private\src\master\Kudu.Core\Infrastructure\OperationManager.cs:line 57 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at Kudu.Core.Infrastructure.OperationManager.<AttemptAsync>d__5`1.MoveNext() in C:\Kudu Files\Private\src\master\Kudu.Core\Infrastructure\OperationManager.cs:line 75 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Kudu.Core.Helpers.PostDeploymentHelper.<TryFunctionsRuntimeSyncTriggers>d__38.MoveNext() in C:\Kudu Files\Private\src\master\Kudu.Core\Helpers\PostDeploymentHelper.cs:line 302" date="2024-04-25T17:42:22.103"/>
<!--  duration: 16ms  -->
<step title="Attempting to perform settriggers call directly." date="2024-04-25T17:42:22.134"/>
<!--  duration: 16ms  -->
<step title="Syncing httpTrigger of ClerkEndpoint" date="2024-04-25T17:42:22.243"/>
<!--  duration: 31ms  -->
<step title="Syncing httpTrigger of GraphQLEndpoint" date="2024-04-25T17:42:22.290"/>
<!--  duration: 31ms  -->
<step title="Skipping graphQL of GraphQLEndpoint" date="2024-04-25T17:42:22.337"/>
<!--  duration: 16ms  -->
<step title="Syncing httpTrigger of PingEndpoint" date="2024-04-25T17:42:22.384"/>
<!--  duration: 47ms  -->
<step title="Syncing httpTrigger of StripeEndpoint" date="2024-04-25T17:42:22.446"/>
<!--  duration: 16ms  -->
<step title="Syncing warmupTrigger of Warmup" date="2024-04-25T17:42:22.478"/>
<!--  duration: 31ms  -->
<step title="Begin HttpPost https://redacted-functions.scm.azurewebsites.net/operations/settriggers, x-ms-request-id: 2442b05a-458d-407f-a36f-ee2b2e660d76" date="2024-04-25T17:42:22.540"/>
<!--  duration: 16ms  -->
<step title="End HttpPost, status: OK" date="2024-04-25T17:42:22.728"/>
<!--  duration: 16ms  -->
<step title="Syncing 5 function triggers with payload size 628 bytes successful." date="2024-04-25T17:42:22.759"/>
<!--  duration: 16ms  -->
<step title="Deleting shutdown sentinel file" date="2024-04-25T17:42:22.821" SemaphoreCount="8"/>
<!--  duration: 16ms  -->
</step>
<!--  duration: 63545ms  -->

Activity log shows this error:

{
    "authorization": {
        "action": "Microsoft.Web/sites/host/sync/action",
        "scope": "/subscriptions/redacted/resourceGroups/redacted/providers/Microsoft.Web/sites/redacted-functions/host/default"
    },
    "caller": "redacted",
    "channels": "Operation",
    "claims": {
    [...]
    },
    "correlationId": "97decc8c-f17f-4aa0-9123-f59d7a12bf99",
    "description": "",
    "eventDataId": "0def156f-c83f-403e-9b44-4953e0eb9e62",
    "eventName": {
        "value": "EndRequest",
        "localizedValue": "End request"
    },
    "category": {
        "value": "Administrative",
        "localizedValue": "Administrative"
    },
    "eventTimestamp": "2024-04-29T02:23:01.7365522Z",
    "id": "/subscriptions/redacted/resourceGroups/redacted/providers/Microsoft.Web/sites/redacted-functions/host/default/events/0def156f-c83f-403e-9b44-4953e0eb9e62/ticks/638499541817365522",
    "level": "Error",
    "operationId": "bfa3928d-a50f-4c0c-b76c-ab815522fa9b",
    "operationName": {
        "value": "Microsoft.Web/sites/host/sync/action",
        "localizedValue": "Sync Web Apps Function Triggers"
    },
    "resourceGroupName": "redacted",
    "resourceProviderName": {
        "value": "Microsoft.Web",
        "localizedValue": "Azure Web Sites"
    },
    "resourceType": {
        "value": "Microsoft.Web/sites/host",
        "localizedValue": "Microsoft.Web/sites/host"
    },
    "resourceId": "/subscriptions/redacted/resourceGroups/redacted/providers/Microsoft.Web/sites/redacted-functions/host/default",
    "status": {
        "value": "Failed",
        "localizedValue": "Failed"
    },
    "subStatus": {
        "value": "BadRequest",
        "localizedValue": "Bad Request (HTTP Status Code: 400)"
    },
    "submissionTimestamp": "2024-04-29T02:26:03Z",
    "subscriptionId": "redacted",
    "tenantId": "7eb49dfd-a75d-4a38-9690-3b68b5efe173",
    "properties": {
        "statusCode": "BadRequest",
        "serviceRequestId": null,
        "statusMessage": "{\"Code\":\"BadRequest\",\"Message\":\"Encountered an error (InternalServerError) from host runtime.\",\"Target\":null,\"Details\":[{\"Message\":\"Encountered an error (InternalServerError) from host runtime.\"},{\"Code\":\"BadRequest\"},{\"ErrorEntity\":{\"Code\":\"BadRequest\",\"Message\":\"Encountered an error (InternalServerError) from host runtime.\"}}],\"Innererror\":null}",
        "eventCategory": "Administrative",
        "entity": "/subscriptions/redacted/resourceGroups/redacted/providers/Microsoft.Web/sites/redacted-functions/host/default",
        "message": "Microsoft.Web/sites/host/sync/action",
        "hierarchy": "7eb49dfd-a75d-4a38-9690-3b68b5efe173/redacted"
    },
    "relatedEvents": []
}

Related information

Provide any related information

.NET 6, C#
Microsoft.NET.Sdk.Functions: 4.3.0

@liliankasem
Copy link
Member

Hi @kirk-marple - for issues like this, please open a support ticket via the azure portal so that our team can investigate your prod application. Thanks!

@kirk-marple
Copy link
Author

Hi @kirk-marple - for issues like this, please open a support ticket via the azure portal so that our team can investigate your prod application. Thanks!

No worries, I'll open a ticket, and close this out. Thanks!

@kirk-marple
Copy link
Author

Support request filed: 2404290010004411 @liliankasem

@Kerryliu
Copy link

We are having the exact same issue as you described. What's odd is our stacks are identical between stages, and it's working perfectly fine in DEV.

@kirk-marple kirk-marple reopened this May 1, 2024
@kirk-marple
Copy link
Author

kirk-marple commented May 1, 2024

@liliankasem I believe I may have figured out the cause of this, and it may be a bug introduced in a recent version of the functions host. I'm talking to support about it, but I have a very minimal repro where calling 'builder.Services.AddAuthorization' in the FunctionsStartup class makes the /admin/host/status GET fail with a 500 error.

I'm seeing a few other reported bugs similar to this.

#10033
#10032

Happy to get you a link to the sample code to show you the repro.

@liliankasem
Copy link
Member

Repro code would be great, thanks!

@kirk-marple
Copy link
Author

Repro code would be great, thanks!

Here you go:
https://github.com/graphlit/azure-functions-host-repro

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants