Function is not loaded by the language worker (Python)

[Josh-a-e]

Investigative information

(Happens pretty regularly, but a recent example)

• Timestamp: 2020-05-04 13:01:29.253
• Function App version: ~3
• Function App name:
• Function name(s) (as appropriate): transfer_items_master
• Invocation ID: b1432525-67e5-42da-b434-68099b1cc8bb
• Operation ID: 94572bb74ba6a44ea42a42e95f46018e
• Region: West Europe

Repro steps

Provide the steps required to reproduce the problem:

1. Deploy function on a timer trigger
2. Wait for invocation

Expected behavior

The function actually runs reliably

Actual behavior

The function doesn't get executed. Unhelpfully, on occasion, it does, however.

Provides these error messages:

DATE (UTC)	MESSAGE	LOG LEVEL
2020-05-04 13:57:28.621	Executing 'Functions.transfer_daily_sales' (Reason='Timer fired at 2020-05-04T13:57:28.5566633+00:00', Id=8bfb55f3-148b-4678-a646-c490eeb20e7b)	Information
2020-05-04 13:57:28.630	Trigger Details: UnscheduledInvocationReason: IsPastDue, OriginalSchedule: 2020-05-04T13:30:00.0000000+00:00	Information
2020-05-04 13:57:29.901	Function:transfer_daily_sales is not loaded by the language worker: 29ea43fb-3fe9-4529-b962-3f57e0363568	Error
2020-05-04 13:57:29.901	Executed 'Functions.transfer_daily_sales' (Failed, Id=8bfb55f3-148b-4678-a646-c490eeb20e7b)	Error
2020-05-04 13:57:29.921	Function:transfer_daily_sales is not loaded by the language worker: 29ea43fb-3fe9-4529-b962-3f57e0363568	Error

Known workarounds

Provide a description of any known workarounds.

None that I'm confident in.

Related information

Provide any related information

• Programming language used Python
• Locally works totally fine
• Also Sometimes the function runs (as demonstrated by a message appearing in a slack channel), but then the logs don't always turn up in the "monitor" tab. If it did any one thing reliably, this would be much easier to deal with... I just don't ever know if it's fixed by any action I've taken, or by random luck.

Bindings

{
  "scriptFile": "func.py",
  "disabled": false,
  "bindings": [
    {
      "name": "timer",
      "type": "timerTrigger",
      "direction": "in",
      "schedule": "0 */30 * * * *",
      "runOnStartup": false
    }
  ]
}

ARM Config

{
   // ...
    "properties": {
        "name": "[variables('functionAppName')]",
        "enabled": true,
        "serverFarmId": "[resourceId('microsoft.web/serverfarms', variables('appServicePlanName'))]",
        "httpsOnly": true,
        "reserved": true,
        "linuxFxVersion": "DOCKER|microsoft/azure-functions-python3.6:2.0",
        "siteConfig": {
            "http20Enabled": true,
            "numberOfWorkers": 1,
            "use32BitWorkerProcess": false,
            "ftpsState": "FtpsOnly",
            "appSettings": [
                {
                    "name": "AzureWebJobsStorage",
                    "value": "[concat('DefaultEndpointsProtocol=https;AccountName=',variables('functionStorageName'),';AccountKey=',listKeys(resourceId('microsoft.storage/storageAccounts', variables('functionStorageName')), '2016-01-01').keys[0].value)]"
                },
                {
                    "name": "AzureDataStorage",
                    "value": "[concat('DefaultEndpointsProtocol=https;AccountName=',variables('dataStorageName'),';AccountKey=',listKeys(resourceId('microsoft.storage/storageAccounts', variables('dataStorageName')), '2016-01-01').keys[0].value)]"
                },
                {
                    "name": "AzureWebJobsDisableHomepage",
                    "value": "false"
                },
                {
                    "name": "APPINSIGHTS_INSTRUMENTATIONKEY",
                    "value": "[reference(concat('microsoft.insights/components/', variables('appInsightsName'))).InstrumentationKey]"
                },
                {
                    "name": "FUNCTION_APP_EDIT_MODE",
                    "value": "readonly"
                },
                {
                    "name": "FUNCTIONS_EXTENSION_VERSION",
                    "value": "~3"
                },
                {
                    "name": "FUNCTIONS_WORKER_RUNTIME",
                    "value": "python"
                },
                {
                    "name": "WEBSITE_CONTENTAZUREFILECONNECTIONSTRING",
                    "value": "[concat('DefaultEndpointsProtocol=https;AccountName=',variables('functionStorageName'),';AccountKey=',listKeys(resourceId('microsoft.storage/storageAccounts', variables('functionStorageName')), '2016-01-01').keys[0].value)]"
                },
                {
                    "name": "WEBSITE_CONTENTSHARE",
                    "value": "[toLower(variables('functionAppName'))]"
                },
                {
                    "name": "WEBSITE_RUN_FROM_PACKAGE",
                    "value": "1"
                }
               // ...
            ]
        }
    }
}

[Pentusha]

I facing the same problem, but with the http trigger.

[pragnagopa]

cc @Hazhzeng for triage

[anirudhgarg]

Thanks for reporting - we will have a look.

@Pentusha - can you also share your app name

[Pentusha]

@anirudhgarg I have lot of apps with this issue. e.g. qa-client-users-eus-func

[anirudhgarg]

@Pentusha - how long are your invocations expected to run.

[davidweterings]

@anirudhgarg we're running into this issue with multiple function apps as well, f.e. gd-nl-rr-t-we-func-payment and gd-nl-wl-t-we-func-payment When checking live metrics of application insights for these functionapps we see tons of workers when there's not a lot of traffic, so my guess is that some of the workers are zombie processes which are not being cleaned up correctly. We still have gd-nl-t-wl-we-func-payment that is completely broken (and a few more if you want to debug more).

Most of these are http healtcheck calls which don't take more than a second to run.