Azure-functions-core-tools: Linux Python func: Error calling sync triggers (BadRequest).

Created on 28 Jun 2019 · 17Comments · Source: Azure/azure-functions-core-tools

Hi,

Hitting this issue with deploying my Python Linux function looks like it's a common one (#1130) but couldn't see how to fix. Going to try recreating a new app in a different region for now but due to project need to understand and resolve to allow deployment to for a specific region.

Setup:

Ubuntu Machine
func --version 2.7.1373
westeurope deployment
app name lgpyfunc

(.venv) ✔ ~/source/hacks/-/pipeline/pythonfunc [lg/pythonfunc L|…1] 
10:38 $ func azure functionapp publish lgpyfunc --build-native-deps
Microsoft (R) Build Engine version 16.1.76+g14b0a930a7 for .NET Core
Copyright (C) Microsoft Corporation. All rights reserved.

  Restore completed in 38.29 ms for /home/lawrence/source/hacks/-/pipeline/pythonfunc/extensions.csproj.
  extensions -> /home/lawrence/source/hacks/-/pipeline/pythonfunc/bin/extensions.dll

Build succeeded.
    0 Warning(s)
    0 Error(s)

Time Elapsed 00:00:01.36


Getting site publishing info...
Deleting the old .python_packages directory
Running 'docker pull mcr.microsoft.com/azure-functions/python:2.0.12493-python3.6-buildenv'...done
Running 'docker exec -t f76d54 chmod +x /python_docker_build.sh'..done
Running 'docker exec -t f76d54 /python_docker_build.sh'....................................................................................done
Running 'docker cp f76d54:"/.python_packages/." "/home/lawrence/source/hacks/-/pipeline/pythonfunc/.python_packages"'...done
Running 'docker kill f76d54'...done


Running 'docker exec -t f9973a chmod +x /ziptofs.sh'..done
Running 'docker exec -t f9973a /ziptofs.sh'...........................................................................................................................................................................................done
Running 'docker cp f9973a:"/file.squashfs" "/tmp/tmp7xtZpt.tmp"'...done
Running 'docker kill f9973a'...done
Uploading package...
Uploading 812.96 MB [-----------------------------------------------------------------------------]

#############################################################################]
Upload completed successfully.
Deployment completed successfully.
Syncing triggers...
Syncing triggers...
Syncing triggers...
Syncing triggers...
Syncing triggers...
Syncing triggers...
Error calling sync triggers (BadRequest).

Needs

Source

lawrencegripper

All 17 comments

Think this relates to https://github.com/Azure/Azure-Functions/issues/1170

lawrencegripper on 28 Jun 2019

I've retried by creating a new app

az functionapp create --resource-group temp-pyfunc --os-type Linux --consumption-plan-location westeurope  --runtime python --name lgpyfunc2 --storage-account  lgpyfunc1

and now receive a different error:

Directory .python_packages already in sync with requirements.txt. Skipping restoring dependencies...
Running 'docker exec -t 107753 chmod +x /ziptofs.sh'..done
Running 'docker exec -t 107753 /ziptofs.sh'.......................................................................................................................................................done
Running 'docker cp 107753:"/file.squashfs" "/tmp/tmpwgR0A2.tmp"'...done
Running 'docker kill 107753'...done
Uploading package...
Uploading 812.96 MB [#############################################################################]
Upload completed successfully.
Deployment completed successfully.
Syncing triggers...
Syncing triggers...
Syncing triggers...
Syncing triggers...
Syncing triggers...
Syncing triggers...
Error calling sync triggers (Unauthorized).

Just repeating the upload process to see if I continue to get this error of it changes back to the original error.

lawrencegripper on 28 Jun 2019

When retrying this fell back to giving the previously reported error. I'm wondering if this is related to the size of the package (812mb) due to ML stuff (Spacy word vectors) as I had success with a smaller function earlier in the week.

Going to retry with a smaller function and see if this succeeds. Are their logs I can look at on the funcs in the portal or Kudu to see error details?

lawrencegripper on 28 Jun 2019

So I found an issue that seems to contribute. The docs suggest using a virtual environment but don't suggest adding the folder to the .funcignore https://github.com/MicrosoftDocs/azure-docs/issues/34204

Dropping the size of the package seems to result in this error going away. What is the limit for the package size as this will affect the models we can ship?

lawrencegripper on 28 Jun 2019

@lawrencegripper, thanks for pointing that out. You are right that our documentation should suggest adding the virtualenv to .funcignore. @asavaritayal for fyi.

azure-functions-core-tools does indeed try to add that when you do a func init, if it detects one. But, I am guessing you didn't have to perform an init, so it didn't do that.

Before I answer the size of the package issue, are you on Linux Dedicated plan or a Consumption plan? And what version of azure-functions-core-tools did you use?

ankitkumarr on 29 Jun 2019

👍1

Thanks, makes sense.

Version of CLI: ‘func --version 2.7.1373’

Yes attempting to deploy to consumption plan.

(Sorry for brevity on my phone)

lawrencegripper on 1 Jul 2019

I tried dockerizing the image and tested that locally. When I did this I saw an error reported in the docker output saying that azure-functions==1.0.0b5 wasn't supported by the runtime.

I'm not entirely clear why I had this in my requirements.txt, I ended up adding it to fix my IDE tooling moaning at me and just took the latest from pip.

On a hunch I dropped the version azure-functions==1.0.0b4 and retried publishing to the consumption plan, I also moved to a smaller spacy word vector 600mb -> 60mb and it worked.

Then very excited I moved back to the larger model leaving azure-functions==1.0.0b4. This also worked but oddly when reporting the Invoke URL the code= section was missing and looking in the portal the function app showed no functions under it and it didn't respond when called.

Repeating the same command again, in an attempt to resolve this, returned the original error of Bad Request

Dropping back to the smaller model and republishing gave the expected result so I'm now fairly convinced that the size of the package is having an affect here.

Is there a way I can output more verbose logging from the func tooling?

Console logs below.

PUBLISH WITH SMALLER MODEL AND 1.0.0b4

16:11 $ func azure functionapp publish lgpyfunc --build-native-deps
Microsoft (R) Build Engine version 16.1.76+g14b0a930a7 for .NET Core
Copyright (C) Microsoft Corporation. All rights reserved.

  Restore completed in 24.22 ms for /home/lawrence/source/hacks/-/pipeline/pythonfunc/extensions.csproj.
  extensions -> /home/lawrence/source/hacks/-/pipeline/pythonfunc/bin/extensions.dll

Build succeeded.
    0 Warning(s)
    0 Error(s)

Time Elapsed 00:00:00.85


Getting site publishing info...
Deleting the old .python_packages directory
Running 'docker pull mcr.microsoft.com/azure-functions/python:2.0.12493-python3.6-buildenv'..done
Running 'docker exec -t e7082d chmod +x /python_docker_build.sh'..done
Running 'docker exec -t e7082d /python_docker_build.sh'.........................................................................done
Running 'docker cp e7082d:"/.python_packages/." "/home/lawrence/source/hacks/-/pipeline/pythonfunc/.python_packages"'...done
Running 'docker kill e7082d'...done
Running 'docker exec -t d23ebb chmod +x /ziptofs.sh'..done
Running 'docker exec -t d23ebb /ziptofs.sh'..........................done
Running 'docker cp d23ebb:"/file.squashfs" "/tmp/tmpg2ySIG.tmp"'..done
Running 'docker kill d23ebb'...done
Uploading package...
Uploading 187.4 MB [##############################################################################]
Upload completed successfully.
Deployment completed successfully.
Syncing triggers...
Functions in lgpyfunc:
    productmatch - [httpTrigger]
        Invoke url: https://lgpyfunc.azurewebsites.net/api/productmatch?code=KEY_HERE_REDACTED


2019/07/01 16:19:41 Current version is the latest

PUBLISH WITH LARGER MODEL AND 1.0.0b4

(.venv) ✔ ~/source/hacks/-/pipeline/pythonfunc [lg/pythonfunc|✚ 4…2] 
16:20 $ func azure functionapp publish lgpyfunc --build-native-deps
Microsoft (R) Build Engine version 16.1.76+g14b0a930a7 for .NET Core
Copyright (C) Microsoft Corporation. All rights reserved.

  Restore completed in 24.89 ms for /home/lawrence/source/hacks/-/pipeline/pythonfunc/extensions.csproj.
  extensions -> /home/lawrence/source/hacks/-/pipeline/pythonfunc/bin/extensions.dll

Build succeeded.
    0 Warning(s)
    0 Error(s)

Time Elapsed 00:00:00.89


Getting site publishing info...
Deleting the old .python_packages directory
Running 'docker pull mcr.microsoft.com/azure-functions/python:2.0.12493-python3.6-buildenv'..done
Running 'docker exec -t 1d4c00 chmod +x /python_docker_build.sh'..done
Running 'docker exec -t 1d4c00 /python_docker_build.sh'..........................................................................................................................................................................................................done
Running 'docker cp 1d4c00:"/.python_packages/." "/home/lawrence/source/hacks/-/pipeline/pythonfunc/.python_packages"'....done
Running 'docker kill 1d4c00'...done
Running 'docker exec -t 3b14e3 chmod +x /ziptofs.sh'..done
Running 'docker exec -t 3b14e3 /ziptofs.sh'.....................................done
Running 'docker cp 3b14e3:"/file.squashfs" "/tmp/tmpAURpmW.tmp"'...done
Running 'docker kill 3b14e3'..done
Uploading package...
Uploading 729.32 MB [-----------------------------------------------------------------------------]
#############################################################################]
Upload completed successfully.
Deployment completed successfully.
Syncing triggers...
Functions in lgpyfunc:
    productmatch - [httpTrigger]
        Invoke url: https://lgpyfunc.azurewebsites.net/api/productmatch

RETRY PUBLISH WITH SMALLER MODEL AND 1.0.0b4

(.venv) ✔ ~/source/hacks/-/pipeline/pythonfunc [lg/pythonfunc|✚ 4…2] 
16:28 $ func azure functionapp publish lgpyfunc --build-native-deps
Microsoft (R) Build Engine version 16.1.76+g14b0a930a7 for .NET Core
Copyright (C) Microsoft Corporation. All rights reserved.

  Restore completed in 29.81 ms for /home/lawrence/source/hacks/-/pipeline/pythonfunc/extensions.csproj.
  extensions -> /home/lawrence/source/hacks/-/pipeline/pythonfunc/bin/extensions.dll

Build succeeded.
    0 Warning(s)
    0 Error(s)

Time Elapsed 00:00:01.07


Getting site publishing info...
Directory .python_packages already in sync with requirements.txt. Skipping restoring dependencies...
Running 'docker exec -t e71385 chmod +x /ziptofs.sh'..done
Running 'docker exec -t e71385 /ziptofs.sh'........................................done
Running 'docker cp e71385:"/file.squashfs" "/tmp/tmpz3Gz5c.tmp"'...done
Running 'docker kill e71385'..done
Uploading package...
Uploading 729.32 MB [-----------------------------------------------------------------------------]
#############################################################################]
Upload completed successfully.
Deployment completed successfully.
Syncing triggers...
Syncing triggers...
Syncing triggers...
Syncing triggers...
Syncing triggers...
Syncing triggers...
Error calling sync triggers (BadRequest).

PUBLISH WITH SMALLER MODEL AND 1.0.0b4

16:39 $ func azure functionapp publish lgpyfunc --build-native-deps
Microsoft (R) Build Engine version 16.1.76+g14b0a930a7 for .NET Core
Copyright (C) Microsoft Corporation. All rights reserved.

  Restore completed in 28.42 ms for /home/lawrence/source/hacks/-/pipeline/pythonfunc/extensions.csproj.
  extensions -> /home/lawrence/source/hacks/-/pipeline/pythonfunc/bin/extensions.dll

Build succeeded.
    0 Warning(s)
    0 Error(s)

Time Elapsed 00:00:01.09


Getting site publishing info...
Deleting the old .python_packages directory
Running 'docker pull mcr.microsoft.com/azure-functions/python:2.0.12493-python3.6-buildenv'..done
Running 'docker exec -t 2eeaf2 chmod +x /python_docker_build.sh'..done
Running 'docker exec -t 2eeaf2 /python_docker_build.sh'........................................................................done
Running 'docker cp 2eeaf2:"/.python_packages/." "/home/lawrence/source/hacks/-/pipeline/pythonfunc/.python_packages"'...done
Running 'docker kill 2eeaf2'...done
Running 'docker exec -t e63a5f chmod +x /ziptofs.sh'..done
Running 'docker exec -t e63a5f /ziptofs.sh'..........................done
Running 'docker cp e63a5f:"/file.squashfs" "/tmp/tmpFVtcF0.tmp"'..done
Running 'docker kill e63a5f'...done
Uploading package...
Uploading 187.4 MB [##############################################################################]
Upload completed successfully.
Deployment completed successfully.
Syncing triggers...
Functions in lgpyfunc:
    productmatch - [httpTrigger]
        Invoke url: https://lgpyfunc.azurewebsites.net/api/productmatch?code=REDACTED_KEY_HERE

lawrencegripper on 1 Jul 2019

Would it be useful for me to upload a zip of a function which reproduces this?

lawrencegripper on 1 Jul 2019

I'm having this issue at the moment, EastAsia region. It was working fine yesterday

jsjayme on 2 Jul 2019

So I had a play with creating a PR for the tooling to add a --verbose setting to output the information from the failed request. While writing it I discovered the CLI_DEBUG=1 environment variable which did exactly what I wanted.

Here is the output from the publish with this enabled (minus auth headers), unfortunately not much useful data in the response for me but I'm hoping the x-ms-correlation-request-id is useful for the engineering team to debug further:

Request:
Method: POST, RequestUri: 'https://management.azure.com/subscriptions/REDACTED_HERE/resourceGroups/temp-pyfunc/providers/Microsoft.Web/sites/lgpyfunc/hostruntime/admin/host/synctriggers?api-version=2015-08-01', Version: 2.0, Content: System.Net.Http.StringContent, Headers:
{
  Authorization: Bearer REDACTED
  User-Agent: functions-core-tools/2.7.1
  Accept: application/json
  x-ms-request-id: f7c3b653-fa2a-47f1-a0d7-55fea7d1d7fa
  Content-Type: application/json; charset=utf-8
}
null

Response:
StatusCode: 400, ReasonPhrase: 'Bad Request', Version: 1.1, Content: System.Net.Http.HttpConnection+HttpConnectionResponseContent, Headers:
{
  Cache-Control: no-cache
  Pragma: no-cache
  Strict-Transport-Security: max-age=31536000; includeSubDomains
  Server: Microsoft-IIS/10.0
  X-AspNet-Version: 4.0.30319
  X-Powered-By: ASP.NET
  x-ms-ratelimit-remaining-subscription-writes: 1196
  x-ms-request-id: 468ff57b-7a89-4775-84e9-42aaaaf01270
  x-ms-correlation-request-id: 468ff57b-7a89-4775-84e9-42aaaaf01270
  x-ms-routing-request-id: NORTHEUROPE:20190702T094845Z:468ff57b-7a89-4775-84e9-42aaaaf01270
  X-Content-Type-Options: nosniff
  Date: Tue, 02 Jul 2019 09:48:45 GMT
  Content-Length: 349
  Content-Type: application/json; charset=utf-8
  Expires: -1
}
{"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}

lawrencegripper on 2 Jul 2019

Having this issue on EastUS as well. Just created an issue here: https://github.com/Azure/azure-functions-core-tools/issues/1457

zacktayl on 24 Jul 2019

Hello there people.

I am having exactly the same issue.

Error: Failed to sync triggers for function app 'name-of-the-app-here'. Error: BadRequest - Encountered an error (InternalServerError) from host runtime. (CODE: 400)

Also for my case i was using the Azure Devops pipeline.

I noticed though that in my case the Function App is not dissappearing after the failed deployment.

But for some reason i get the following error.

Error:

Encountered an error (InternalServerError) from host runtime.
Session Id: ------------------------------------------ ( just removed the session id but can provide it if needed ).

Timestamp: 2019-07-25T09:28:19.971Z

Any updates on this issue?

Function app running on WestEU as a consumption plan. Python for Linux runtime.

thedoupub on 25 Jul 2019

@ankitkumarr i think it would help a lot if we would know the max size in mbs for the actual package in python. Since after quite a long search i was not able to find any information at all for this.
:(

thedoupub on 25 Jul 2019

👍1

katlimruiz on 20 Aug 2019

Hi, I apologize for the super delayed response here. The original report here was resolved in an offline internal thread.
The thing is SyncTriggers is the first call that is made on the Function App. So, it failing could mean a lot of things - function app is down, App didn't update, etc. Usually, we want to look at these issues on a case by case basis.

If you are using a Linux App Service plan, we made some improvements in our platform to use RunFromPackage, which should help a ton with deployment times and make it a lot more reliable issue.
I have a PR open to update our tooling to use this by default which should be available in the next release later this week (just need to do a final testing pass). In the meanwhile, you can try to add an Application Setting WEBSITE_RUN_FROM_PACKAGE=1 and they publish as you would.

If you do continue to see issue, please share you Function App name and a repro, and ideally open a new issue so we can look at your case specifically.

About the max size, I wanted to wait for our improvements to land, and in the coming weeks I can do some testing and see if there's a specific max size that we need to call out.

ankitkumarr on 20 Aug 2019

👍1

I deleted my function app Linux and created a windows one and it worked, so it seems Azure has some bugs in the Linux app.
On Aug 20, 2019, 16:32 -0500, Ankit Kumar notifications@github.com, wrote:

Hi, I apologize for the super delayed response here. The original report here was resolved in an offline internal thread.
The thing is SyncTriggers is the first call that is made on the Function App. So, it failing could mean a lot of things - function app is down, App didn't update, etc. Usually, we want to look at these issues on a case by case basis.
If you are using a Linux App Service plan, we made some improvements in our platform to use RunFromPackage, which should help a ton with deployment times and make it a lot more reliable issue.
I have a PR open to update our tooling to use this by default which should be available in the next release later this week (just need to do a final testing pass). In the meanwhile, you can try to add an Application Setting WEBSITE_RUN_FROM_PACKAGE=1 and they publish as you would.
If you do continue to see issue, please share you Function App name and a repro, and ideally open a new issue so we can look at your case specifically.
About the max size, I wanted to wait for our improvements to land, and in the coming weeks I can do some testing and see if there's a specific max size that we need to call out.
—
You are receiving this because you commented.
Reply to this email directly, view it on GitHub, or mute the thread.

katlimruiz on 22 Aug 2019

Closing as this was fixed on the backend, if you continue seeing this issue please open a new issue