Oryx
Oryx copied to clipboard
microsoft
Azure Function App Deployment Fails with "An unknown error has occurred" (Python 3.8, Linux App Service)
Bug Report
At what date and time did you most recently experience the problem?
One instance:
Start: Fri, 15 Jul 2022 19:19:22 GMT
End: Fri, 15 Jul 2022 19:45:49 GMT
We've experienced this problem consistently for months now. The deployment fails about half the time, if not more, and when it does, it can't be killed. It just hangs for 30 minutes and blocks other deployments from working.
Where did you experience the problem? E.g. Azure Web Apps, Azure Functions, Azure Container Registry, or offline use.
Azure Function App
If your repo is publicly available please share its URL:
Not public, but happy to put together a shell of our app if need be
What happened?
Deployment failed, but also hung for 30 minutes. During that period of time, other deployments fail because of the deployment that is currently in progress.
What did you expect or want to happen?
Either successful deployment or at least quickly exit after failure.
Perhaps relevant: We have an SPA in a separate repo that we deploy at the same time, so we'd prefer not to use the Azure Function App deploy triggers that listen on a repo+branch. (Under the Deployment Center blade)
How can we reproduce it?
- Linux Function App on P1V2, Python 3.8 Runtime
- ENABLE_ORYX_BUILD=true
- SCM_DO_BUILD_DURING_DEPLOYMENT=1
- Full function specs here: function-app.txt
- Deploy with
func azure functionapp publish(GitHub Action here: github-action.txt) - Directory structure below:
proxies.json
{
"$schema": "http://json.schemastore.org/proxies",
"proxies": {}
}
local.settings.json
{
"IsEncrypted": false,
"Values": {
"FUNCTIONS_WORKER_RUNTIME": "python",
"AzureWebJobs.app.Disabled": "false"
}
}
host.json
{
"version": "2.0",
"logging": {
"applicationInsights": {
"samplingSettings": {
"isEnabled": true,
"excludedTypes": "Request"
}
}
},
"extensionBundle": {
"id": "Microsoft.Azure.Functions.ExtensionBundle",
"version": "2.6.1"
},
"extensions": {
"http": {
"routePrefix": ""
}
}
}
setup.py
from setuptools import setup
packages = []
with open("requirements/aws.txt", "r") as f:
requirements = f.read().splitlines()
setup(
name="flank-api",
version="0.1.0",
description="example api to be deployed to aws lambda",
# url="http://github.com/iwpnd/fastapi-aws-lambda-example",
author="Angus Mitchell",
author_email="[email protected]",
license="MIT",
include_package_data=True,
install_requires=requirements,
packages=packages,
zip_safe=False,
classifiers=[
"Programming Language :: Python :: 3",
"Intended Audience :: Developers",
],
)
Do you have log output? Please include between the backticks:
The logs that get printed to GitHub Actions (full logs here: 11_Deploy the function.txt)
Running oryx build...
Command: oryx build /tmp/zipdeploy/extracted -o /tmp/build/expressbuild --platform python --platform-version 3.8 -i /tmp/8da669726cad858 -p packagedir=.python_packages/lib/site-packages
Operation performed by Microsoft Oryx, https://github.com/Microsoft/Oryx
You can report issues at https://github.com/Microsoft/Oryx/issues
Oryx Version: 0.2.20220308.[4](https://github.com/btf-org/flank-api/runs/7363820123?check_suite_focus=true#step:11:4), Commit: c92fa6a2d6fc14dc9646f80e2bb2e393a[5](https://github.com/btf-org/flank-api/runs/7363820123?check_suite_focus=true#step:11:5)cdc258, ReleaseTagName: 20220308.4
Build Operation ID: |[6](https://github.com/btf-org/flank-api/runs/7363820123?check_suite_focus=true#step:11:6)uRUisqcsUc=.24a16c09_
Repository Commit : 2[7](https://github.com/btf-org/flank-api/runs/7363820123?check_suite_focus=true#step:11:7)a7a1a7-9cc2-4e45-[8](https://github.com/btf-org/flank-api/runs/7363820123?check_suite_focus=true#step:11:8)7a6-0fea3d4[9](https://github.com/btf-org/flank-api/runs/7363820123?check_suite_focus=true#step:11:9)5ec6
Detecting platforms...
An unknown error has occurred. Check the diagnostic log for details.
Remote build failed!
Error: Process completed with exit code 1.
##[debug]Finishing: Deploy the function
From the log archives, the runner (full logs here: Runner_20220715-191915-utc.log)
[2022-07-15 19:19:16Z ERR JobNotification] Connection to monitor port 49100 failed!
[2022-07-15 19:19:16Z ERR JobNotification] System.Net.Internals.SocketExceptionFactory+ExtendedSocketException (111): Connection refused [::ffff:127.0.0.1]:49100
at System.Net.Sockets.Socket.DoConnect(EndPoint endPointSnapshot, SocketAddress socketAddress)
at System.Net.Sockets.Socket.Connect(EndPoint remoteEP)
at System.Net.Sockets.Socket.Connect(IPAddress address, Int32 port)
at GitHub.Runner.Common.JobNotification.ConnectMonitor(String monitorSocketAddress)
From the log archive, the worker (Full logs here: Worker_20220715-191921-utc.log)
[2022-07-15 19:45:46Z INFO JobServer] Caught exception during append web console line to websocket, let's fallback to sending via non-websocket call (total calls: 106, failed calls: 1, websocket state: Open).
[2022-07-15 19:45:46Z ERR JobServer] System.Net.WebSockets.WebSocketException (2): The remote party closed the WebSocket connection without completing the close handshake. ---> System.IO.IOException: Unable to write data to the transport connection: Broken pipe.
---> System.Net.Sockets.SocketException (32): Broken pipe
at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.CreateException(SocketError error, Boolean forAsyncThrow)
at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.SendAsyncForNetworkStream(Socket socket, CancellationToken cancellationToken)
at System.Net.Sockets.NetworkStream.WriteAsync(ReadOnlyMemory`1 buffer, CancellationToken cancellationToken)
at System.Net.Security.SslStream.WriteSingleChunk[TIOAdapter](TIOAdapter writeAdapter, ReadOnlyMemory`1 buffer)
at System.Net.Security.SslStream.WriteAsyncInternal[TIOAdapter](TIOAdapter writeAdapter, ReadOnlyMemory`1 buffer)
at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
at System.Net.Security.SslStream.WriteAsync(ReadOnlyMemory`1 buffer, CancellationToken cancellationToken)
at System.Net.Http.HttpConnection.WriteToStreamAsync(ReadOnlyMemory`1 source, Boolean async)
at System.Net.Http.HttpConnection.RawConnectionStream.WriteAsync(ReadOnlyMemory`1 buffer, CancellationToken cancellationToken)
at System.Net.WebSockets.ManagedWebSocket.SendFrameFallbackAsync(MessageOpcode opcode, Boolean endOfMessage, Boolean disableCompression, ReadOnlyMemory`1 payloadBuffer, Task lockTask, CancellationToken cancellationToken)
at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
at System.Net.WebSockets.ManagedWebSocket.SendFrameFallbackAsync(MessageOpcode opcode, Boolean endOfMessage, Boolean disableCompression, ReadOnlyMemory`1 payloadBuffer, Task lockTask, CancellationToken cancellationToken)
at System.Net.WebSockets.ManagedWebSocket.SendAsync(ReadOnlyMemory`1 buffer, WebSocketMessageType messageType, WebSocketMessageFlags messageFlags, CancellationToken cancellationToken)
at System.Net.WebSockets.ManagedWebSocket.SendAsync(ArraySegment`1 buffer, WebSocketMessageType messageType, Boolean endOfMessage, CancellationToken cancellationToken)
at GitHub.Runner.Common.JobServer.AppendTimelineRecordFeedAsync(Guid scopeIdentifier, String hubName, Guid planId, Guid timelineId, Guid timelineRecordId, Guid stepId, IList`1 lines, Nullable`1 startLine, CancellationToken cancellationToken)
at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
at GitHub.Runner.Common.JobServer.AppendTimelineRecordFeedAsync(Guid scopeIdentifier, String hubName, Guid planId, Guid timelineId, Guid timelineRecordId, Guid stepId, IList`1 lines, Nullable`1 startLine, CancellationToken cancellationToken)
at GitHub.Runner.Common.JobServerQueue.ProcessWebConsoleLinesQueueAsync(Boolean runOnce)
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.MoveNext(Thread threadPoolThread)
at System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(IAsyncStateMachineBox box, Boolean allowInlining)
at System.Threading.Tasks.Task.RunContinuations(Object continuationObject)
at System.Threading.Tasks.Task.DelayPromise.CompleteTimedOut()
at System.Threading.TimerQueueTimer.Fire(Boolean isThreadPool)
at System.Threading.ThreadPoolWorkQueue.Dispatch()
at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()
at System.Threading.Thread.StartCallback()
--- End of stack trace from previous location ---
If this is helpful, at all, here are some of the logs off of the App Service's SCM Site. I pulled them from the Bash tab. I'm not sure what the difference is between the "Bash" tab and the "SSH" tab. Interestingly, the same file exists at the same location on whatever machine SSH leads to.
/home/DeploymentLogStream>cat a2d831bc-d89d-4770-85ed-07378f75243f.log
{"timestamp": "2022-07-18T22:05:57.339Z", "level": "Message", "containerName": "b6b71c4f1d0e", "machineName": "pl1sdlwk00088D", "message": "Updating submodules."}
{"timestamp": "2022-07-18T22:05:57.507Z", "level": "Message", "containerName": "b6b71c4f1d0e", "machineName": "pl1sdlwk00088D", "message": "Preparing deployment for commit id 'a2d831bc-d'."}
{"timestamp": "2022-07-18T22:05:58.008Z", "level": "Message", "containerName": "b6b71c4f1d0e", "machineName": "pl1sdlwk00088D", "message": "PreDeployment: context.CleanOutputPath False"}
{"timestamp": "2022-07-18T22:05:58.232Z", "level": "Message", "containerName": "b6b71c4f1d0e", "machineName": "pl1sdlwk00088D", "message": "PreDeployment: context.OutputPath /home/site/wwwroot"}
{"timestamp": "2022-07-18T22:05:58.392Z", "level": "Message", "containerName": "b6b71c4f1d0e", "machineName": "pl1sdlwk00088D", "message": "Repository path is /tmp/zipdeploy/extracted"}
{"timestamp": "2022-07-18T22:06:00.433Z", "level": "Message", "containerName": "b6b71c4f1d0e", "machineName": "pl1sdlwk00088D", "message": "Running oryx build..."}
{"timestamp": "2022-07-18T22:06:00.449Z", "level": "Message", "containerName": "b6b71c4f1d0e", "machineName": "pl1sdlwk00088D", "message": "Command: oryx build /tmp/zipdeploy/extracted -o /tmp/build/expressbuild --platform python --platform-version 3.8 -i /tmp/8da6909b1556766 -p packagedir=.python_packages/lib/site-packages"}
{"timestamp": "2022-07-18T22:30:49.715Z", "level": "Error", "containerName": "65b34a79af92", "machineName": "pl1sdlwk00088D", "message": "An unknown error has occurred. Check the diagnostic log for details."}
Hi @anguspmitchell,
The error message very likely occurs when we temporarily removed some txt or SDKs files from our storage account, it may be a temporary issue, would you be able to try it again? Do you still face this issue?
Hi @anguspmitchell,
The error message very likely occurs when we temporarily removed some txt or SDKs files from our storage account, it may be a temporary issue, would you be able to try it again? Do you still face this issue?
@qianz2 We've had this issue as far back as June 23rd. Since then we've run the deployment 38 times and had 17 situations in which it has hung.
@qianz2 Did that answer your question? Curious if you've seen this from other people. We're still getting this error ~50% of the time.
@anguspmitchell, the issue appears internally in our team when we publish new SDK versions into the storage account, and the pipeline requires us to remove certain txt files from the storage account. During that period of time, the tests will show errors very similar like you're experiencing and then hung up:
Detecting platforms...
I don't know other customers facing same issue. We recently had a fix for this issue already checked in, so ideally it won't appear again. Please let us know if you're still facing it for certain period of time.