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.

Sign up for GitHub

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

Jump to bottom

Unreliable Zip Deploy #8522

Closed
jdadojr opened this issue Oct 8, 2018 · 13 comments
Closed

Unreliable Zip Deploy #8522

jdadojr opened this issue Oct 8, 2018 · 13 comments
Assignees
@SumiranAgg @kmkumaran @chshrikh
Labels
Area: AzureAppService Label to monitor Azure App Service issues Area: Release

Comments

@jdadojr
Copy link

jdadojr commented Oct 8, 2018

Troubleshooting

Text logs below

Environment

  • Server - Azure Release Pipelines

  • Agent - Private:

    • If using Hosted agent ; Hosted Agent, Pool: Hosted Ubuntu 1604

Issue Description

Unreliable Release Zip Deployment

Task logs

1st Try
2018-10-08T16:51:55.5416494Z ##[section]Starting: Azure App Service Deploy: apiTfcAppSvr
2018-10-08T16:51:55.5425184Z ==============================================================================
2018-10-08T16:51:55.5425297Z Task : Azure App Service Deploy
2018-10-08T16:51:55.5425447Z Description : Update Azure App Services on Windows, Web App on Linux with built-in images or Docker containers, ASP.NET, .NET Core, PHP, Python or Node.js based Web applications, Function Apps, Mobile Apps, API applications, Web Jobs using Web Deploy / Kudu REST APIs
2018-10-08T16:51:55.5425590Z Version : 3.4.10
2018-10-08T16:51:55.5425656Z Author : Microsoft Corporation
2018-10-08T16:51:55.5425749Z Help : More information
2018-10-08T16:51:55.5425851Z ==============================================================================
2018-10-08T16:51:55.9924165Z Got connection details for Azure App Service:'apiTfcAppSvr'
2018-10-08T16:51:57.6759705Z Package deployment using ZIP Deploy initiated.
2018-10-08T16:56:24.8137440Z Updating submodules.
2018-10-08T16:56:24.8138480Z Preparing deployment for commit id '0cb04468b2'.
2018-10-08T16:56:24.8138897Z Generating deployment script.
2018-10-08T16:56:25.4741472Z Using cached version of deployment script (command: 'azure -y --no-dot-deployment -r "/tmp/zipdeploy/extracted" -o "/home/site/deployments/tools" --basic --sitePath "/tmp/zipdeploy/extracted"').
2018-10-08T16:56:25.4742732Z Running deployment command...
2018-10-08T16:56:25.9427622Z Command: "/home/site/deployments/tools/deploy.sh"
2018-10-08T16:56:25.9428389Z Handling Basic Web Site deployment.
2018-10-08T16:56:25.9429061Z Kudu sync from: '/tmp/zipdeploy/extracted' to: '/home/site/wwwroot'
2018-10-08T16:56:25.9429431Z Ignoring: .git
2018-10-08T16:56:25.9430021Z Copying file: 'node_modules/.bin/json2yaml'
2018-10-08T16:56:25.9430556Z Copying file: 'node_modules/.bin/mkdirp'
2018-10-08T16:56:25.9431431Z Copying file: 'node_modules/.bin/needle'
2018-10-08T16:56:25.9431934Z Copying file: 'node_modules/.bin/node-pre-gyp'
2018-10-08T16:56:25.9432441Z Copying file: 'node_modules/.bin/nopt'
2018-10-08T16:56:25.9432935Z Copying file: 'node_modules/.bin/pbjs'
2018-10-08T16:56:25.9433877Z Copying file: 'node_modules/.bin/pbts'
2018-10-08T16:56:25.9434897Z Copying file: 'node_modules/.bin/pino'
2018-10-08T16:56:25.9435557Z Error: ENOENT: no such file or directory, open '/home/site/wwwroot/node_modules/.bin/pbjs'
2018-10-08T16:56:25.9435988Z An error has occurred during web site deployment.
2018-10-08T16:56:25.9436321Z Kudu Sync failed
2018-10-08T16:56:25.9436632Z \n/opt/Kudu/bin/Scripts/starter.sh "/home/site/deployments/tools/deploy.sh"
2018-10-08T16:56:25.9437140Z App container will begin restart within 10 seconds.
2018-10-08T16:56:25.9508983Z ##[error]Failed to deploy web package to App Service.
2018-10-08T16:56:25.9518657Z ##[error]Error: Package deployment using ZIP Deploy failed. Refer logs for more details.
2018-10-08T16:56:29.1741942Z Successfully updated deployment History at https://apitfcappsvr-staging.scm.azurewebsites.net/api/deployments/331539017786341
2018-10-08T16:56:29.2047936Z ##[section]Finishing: Azure App Service Deploy: apiTfcAppSvr

2nd Try
2018-10-08T17:14:43.1645601Z ##[section]Starting: Azure App Service Deploy: apiTfcAppSvr
2018-10-08T17:14:43.1654021Z ==============================================================================
2018-10-08T17:14:43.1654113Z Task : Azure App Service Deploy
2018-10-08T17:14:43.1654241Z Description : Update Azure App Services on Windows, Web App on Linux with built-in images or Docker containers, ASP.NET, .NET Core, PHP, Python or Node.js based Web applications, Function Apps, Mobile Apps, API applications, Web Jobs using Web Deploy / Kudu REST APIs
2018-10-08T17:14:43.1654467Z Version : 3.4.10
2018-10-08T17:14:43.1654520Z Author : Microsoft Corporation
2018-10-08T17:14:43.1654600Z Help : More information
2018-10-08T17:14:43.1654684Z ==============================================================================
2018-10-08T17:14:43.5861849Z Got connection details for Azure App Service:'apiTfcAppSvr'
2018-10-08T17:14:45.7664407Z Package deployment using ZIP Deploy initiated.
2018-10-08T17:20:36.1862935Z Updating submodules.
2018-10-08T17:20:36.1864555Z Preparing deployment for commit id '69319fe338'.
2018-10-08T17:20:36.1864892Z Generating deployment script.
2018-10-08T17:20:36.7130125Z Using cached version of deployment script (command: 'azure -y --no-dot-deployment -r "/tmp/zipdeploy/extracted" -o "/home/site/deployments/tools" --basic --sitePath "/tmp/zipdeploy/extracted"').
2018-10-08T17:20:36.7131070Z Running deployment command...
2018-10-08T17:20:37.3864686Z Command: "/home/site/deployments/tools/deploy.sh"
2018-10-08T17:20:37.3865061Z Handling Basic Web Site deployment.
2018-10-08T17:20:37.3865632Z Kudu sync from: '/tmp/zipdeploy/extracted' to: '/home/site/wwwroot'
2018-10-08T17:20:37.3866030Z Ignoring: .git
2018-10-08T17:20:37.3866607Z Copying file: 'node_modules/.bin/sshpk-verify'
2018-10-08T17:20:37.3867129Z Copying file: 'node_modules/.bin/uuid'
2018-10-08T17:20:37.3867683Z Copying file: 'node_modules/.bin/yaml2json'
2018-10-08T17:20:37.3868195Z Copying file: 'node_modules/@firebase/app/package.json'
2018-10-08T17:20:37.3868776Z Copying file: 'node_modules/@firebase/app-types/package.json'
2018-10-08T17:20:37.3869364Z Copying file: 'node_modules/@firebase/database/package.json'
2018-10-08T17:20:37.3870320Z Copying file: 'node_modules/@firebase/database/node_modules/@firebase/util/package.json'
2018-10-08T17:20:37.3871292Z Copying file: 'node_modules/@firebase/database/node_modules/tslib/package.json'
2018-10-08T17:20:37.3871959Z Copying file: 'node_modules/@firebase/database-types/package.json'
2018-10-08T17:20:37.3872604Z Copying file: 'node_modules/@firebase/logger/package.json'
2018-10-08T17:20:37.3873292Z Copying file: 'node_modules/@firebase/util/package.json'
2018-10-08T17:20:37.3874293Z Copying file: 'node_modules/@google-cloud/common/package.json'
2018-10-08T17:20:37.3874839Z Copying file: 'node_modules/@google-cloud/common/node_modules/.bin/gp12-pem'
2018-10-08T17:20:37.3875366Z Copying file: 'node_modules/@google-cloud/common/node_modules/.bin/mime'
2018-10-08T17:20:37.3875947Z Copying file: 'node_modules/@google-cloud/common/node_modules/google-auth-library/package.json'
2018-10-08T17:20:37.3876536Z Copying file: 'node_modules/@google-cloud/common/node_modules/google-p12-pem/package.json'
2018-10-08T17:20:37.3877081Z Copying file: 'node_modules/@google-cloud/common/node_modules/gtoken/package.json'
2018-10-08T17:20:37.3877627Z Copying file: 'node_modules/@google-cloud/common/node_modules/is-stream-ended/package.json'
2018-10-08T17:20:37.3878464Z Copying file: 'node_modules/@google-cloud/common/node_modules/mime/package.json'
2018-10-08T17:20:37.3879219Z Copying file: 'node_modules/@google-cloud/common/node_modules/request/package.json'
2018-10-08T17:20:37.3880004Z Copying file: 'node_modules/@google-cloud/common/node_modules/split-array-stream/license'
2018-10-08T17:20:37.3881581Z Copying file: 'node_modules/@google-cloud/common/node_modules/split-array-stream/package.json'
2018-10-08T17:20:37.3882298Z Copying file: 'node_modules/@google-cloud/common/node_modules/split-array-stream/readme.md'
2018-10-08T17:20:37.3883251Z Copying file: 'node_modules/@google-cloud/common/node_modules/split-array-stream/build/src/index.d.ts'
2018-10-08T17:20:37.3884010Z Copying file: 'node_modules/@google-cloud/common/node_modules/split-array-stream/build/src/index.js'
2018-10-08T17:20:37.3884832Z Copying file: 'node_modules/@google-cloud/common/node_modules/split-array-stream/build/src/index.js.map'
2018-10-08T17:20:37.3885380Z Copying file: 'node_modules/@google-cloud/common/node_modules/stream-events/package.json'
2018-10-08T17:20:37.3885896Z Copying file: 'node_modules/@google-cloud/firestore/package.json'
2018-10-08T17:20:37.3886434Z Copying file: 'node_modules/@google-cloud/firestore/node_modules/safe-buffer/package.json'
2018-10-08T17:20:37.3887751Z Copying file: 'node_modules/@google-cloud/pubsub/package.json'
2018-10-08T17:20:37.3888358Z Copying file: 'node_modules/@google-cloud/pubsub/node_modules/.bin/gp12-pem'
2018-10-08T17:20:37.3888896Z Copying file: 'node_modules/@google-cloud/pubsub/node_modules/.bin/mime'
2018-10-08T17:20:37.3889489Z Copying file: 'node_modules/@google-cloud/pubsub/node_modules/.bin/pbjs'
2018-10-08T17:20:37.3890712Z Copying file: 'node_modules/@google-cloud/pubsub/node_modules/.bin/pbts'
2018-10-08T17:20:37.3891570Z Error: ENOENT: no such file or directory, utime '/home/site/wwwroot/node_modules/@google-cloud/pubsub/node_modules/.bin/pbts'
2018-10-08T17:20:37.3892034Z An error has occurred during web site deployment.
2018-10-08T17:20:37.3892368Z Kudu Sync failed
2018-10-08T17:20:37.3892691Z \n/opt/Kudu/bin/Scripts/starter.sh "/home/site/deployments/tools/deploy.sh"
2018-10-08T17:20:37.3893065Z App container will begin restart within 10 seconds.
2018-10-08T17:20:37.3950740Z ##[error]Failed to deploy web package to App Service.
2018-10-08T17:20:37.3959700Z ##[error]Error: Package deployment using ZIP Deploy failed. Refer logs for more details.
2018-10-08T17:20:42.1947884Z Successfully updated deployment History at https://apitfcappsvr-staging.scm.azurewebsites.net/api/deployments/341539019237947
2018-10-08T17:20:42.2374520Z ##[section]Finishing: Azure App Service Deploy: apiTfcAppSvr

3rd Try
It succeeds
..
..
..
2018-10-08T17:59:50.0599136Z Copying file: 'node_modules/grpc/node_modules/npm-packlist/package.json'
2018-10-08T17:59:50.0599811Z Omitting next output lines...
2018-10-08T17:59:50.0600205Z Processed 505 files...
2018-10-08T17:59:50.0600581Z Processed 1355 files...
2018-10-08T17:59:50.0600932Z Processed 2119 files...
2018-10-08T17:59:50.0601556Z Processed 2827 files...
2018-10-08T17:59:50.0601938Z Processed 3500 files...
2018-10-08T17:59:50.0630476Z Processed 4224 files...
2018-10-08T17:59:50.0630995Z Processed 4895 files...
2018-10-08T17:59:50.0631375Z Finished successfully.
2018-10-08T17:59:50.0631825Z Running post deployment command(s)...
2018-10-08T17:59:50.0632225Z Deployment successful.
2018-10-08T17:59:50.0632587Z App container will begin restart within 10 seconds.
2018-10-08T17:59:50.0632969Z Successfully deployed web package to App Service.

As you can see, the 2nd try sort of able to continue where the first try failed ( at pbts ) .
Actually, I have done about 8 tries on this redeployment before things go right.
Before, about 10 tries..

Error logs

2018-10-08T16:56:25.9435557Z Error: ENOENT: no such file or directory, open '/home/site/wwwroot/node_modules/.bin/pbjs'
2018-10-08T16:56:25.9435988Z An error has occurred during web site deployment.
2018-10-08T16:56:25.9436321Z Kudu Sync failed
2018-10-08T16:56:25.9436632Z \n/opt/Kudu/bin/Scripts/starter.sh "/home/site/deployments/tools/deploy.sh"
2018-10-08T16:56:25.9437140Z App container will begin restart within 10 seconds.
2018-10-08T16:56:25.9508983Z ##[error]Failed to deploy web package to App Service.
2018-10-08T16:56:25.9518657Z ##[error]Error: Package deployment using ZIP Deploy failed. Refer logs for more details.
@vincent1173 vincent1173 added the Area: AzureAppService Label to monitor Azure App Service issues label Oct 9, 2018
@SumiranAgg
Copy link
Contributor

We are getting in touch with the Azure App service team to find the root cause for this issue. Will keep this thread updated accordingly.

@SumiranAgg
Copy link
Contributor

@jdadojr CAn you share detailed logs at RM_Customer_Queries@microsoft.com for further investigation.

@sofipacifico
Copy link

Hello everyone, any update regarding this issue. I have the same error!

In advance, thanks!

@SumiranAgg
Copy link
Contributor

@sofipacifico CAn you share detailed logs at RM_Customer_Queries@microsoft.com
To get logs add 'System.debug' variable with value 'true' in your release and redeploy. Collect the logs generated and share.

@jdadojr
Copy link
Author

jdadojr commented Oct 19, 2018

Looks like it is solved
I see a lot of these retries, but eventually, it will succeed.
Deployment status: 0 'Receiving changes.'. retry after 5 seconds
[GET]https://apitfcappdev.scm.azurewebsites.net/api/deployments/latest?deployer=VSTS_ZIP_DEPLOY&time=2018-10-19_19-02-28Z
POLL URL RESULT: {"id":"temp-0ad3ddc7","status":0,"status_text":"Receiving changes.","author_email":"N/A","author":"N/A","deployer":"VSTS_ZIP_DEPLOY","message":"Deploying from pushed zip file","progress":"Fetching changes.","received_time":"2018-10-19T19:02:28.396633Z","start_time":"2018-10-19T19:02:28.396633Z","end_time":null,"last_success_end_time":null,"complete":false,"active":false,"is_temp":true,"is_readonly":false,"url":null,"log_url":null,"site_name":"apitfcappdev"}
Deployment status: 0 'Receiving changes.'. retry after 5 seconds
[GET]https://apitfcappdev.scm.azurewebsites.net/api/deployments/latest?deployer=VSTS_ZIP_DEPLOY&time=2018-10-19_19-02-28Z
POLL URL RESULT: {"id":"506bccf522c94efb9e21d24b4fd210c3","status":1,"status_text":"Building and Deploying '506bccf522c94efb9e21d24b4fd210c3'.","author_email":"N/A","author":"N/A","deployer":"VSTS_ZIP_DEPLOY","message":"Created via a push deployment","progress":"Running deployment command...","received_time":"2018-10-19T19:06:39.829046Z","start_time":"2018-10-19T19:06:40.231065Z","end_time":null,"last_success_end_time":null,"complete":false,"active":false,"is_temp":false,"is_readonly":true,"url":null,"log_url":null,"site_name":"apitfcappdev"}
...
...
...
2018-10-19T19:01:05.1350799Z ##[debug]task result: Succeeded
2018-10-19T19:01:05.1371610Z ##[debug]Processed: ##vso[task.complete result=Succeeded;]

@SumiranAgg
Copy link
Contributor

We are working on making these calls more reliable. Closing the issue now, please fell free to re-open if failure is seen again.

@egiray
Copy link

egiray commented Feb 21, 2019

Hello,

I am still having problem:

2019-02-21T13:24:00.7162377Z ##[section]Starting: Deploy Azure App Service
2019-02-21T13:24:00.7172800Z ==============================================================================
2019-02-21T13:24:00.7172944Z Task : Azure App Service Deploy
2019-02-21T13:24:00.7173048Z Description : Update Azure App Services on Windows, Web App on Linux with built-in images or Docker containers, ASP.NET, .NET Core, PHP, Python or Node.js based Web applications, Function Apps, Mobile Apps, API applications, Web Jobs using Web Deploy / Kudu REST APIs
2019-02-21T13:24:00.7173389Z Version : 3.4.21
2019-02-21T13:24:00.7173450Z Author : Microsoft Corporation
2019-02-21T13:24:00.7173559Z Help : More information
2019-02-21T13:24:00.7173637Z ==============================================================================
2019-02-21T13:24:01.1496875Z Got connection details for Azure App Service:'timesheet-backend'
2019-02-21T13:24:20.8918844Z Package deployment using ZIP Deploy initiated.
2019-02-21T13:25:01.8320020Z Updating submodules.
2019-02-21T13:25:01.8321082Z Preparing deployment for commit id '737d83a86b'.
2019-02-21T13:25:01.8321498Z Generating deployment script.
2019-02-21T13:25:03.1705666Z Using cached version of deployment script (command: 'azure -y --no-dot-deployment -r "/tmp/zipdeploy/extracted" -o "/home/site/deployments/tools" --basic --sitePath "/tmp/zipdeploy/extracted"').
2019-02-21T13:25:03.1705917Z Running deployment command...
2019-02-21T13:25:04.6121811Z Command: "/home/site/deployments/tools/deploy.sh"
2019-02-21T13:25:04.6121950Z Handling Basic Web Site deployment.
2019-02-21T13:25:04.6122305Z Kudu sync from: '/tmp/zipdeploy/extracted' to: '/home/site/wwwroot'
2019-02-21T13:25:04.6122378Z Ignoring: .git
2019-02-21T13:25:04.6122607Z Copying file: 'node_modules/.bin/handlebars'
2019-02-21T13:25:04.6122852Z Copying file: 'node_modules/.bin/js-yaml'
2019-02-21T13:25:04.6123071Z Copying file: 'node_modules/.bin/semver'
2019-02-21T13:25:04.6123310Z Copying file: 'node_modules/.bin/sshpk-conv'
2019-02-21T13:25:04.6123565Z Copying file: 'node_modules/.bin/sshpk-sign'
2019-02-21T13:25:04.6123807Z Copying file: 'node_modules/.bin/sshpk-verify'
2019-02-21T13:25:04.6124027Z Copying file: 'node_modules/.bin/uglifyjs'
2019-02-21T13:25:04.6124465Z Copying file: 'node_modules/.bin/uuid'
2019-02-21T13:25:04.6124802Z Error: ENOENT: no such file or directory, open '/home/site/wwwroot/node_modules/.bin/sshpk-conv'
2019-02-21T13:25:04.6124899Z An error has occurred during web site deployment.
2019-02-21T13:25:04.6124964Z Kudu Sync failed
2019-02-21T13:25:04.6125045Z \n/opt/Kudu/bin/Scripts/starter.sh "/home/site/deployments/tools/deploy.sh"
2019-02-21T13:25:04.6125121Z App container will begin restart within 10 seconds.
2019-02-21T13:25:04.6195870Z ##[error]Failed to deploy web package to App Service.
2019-02-21T13:25:04.6211990Z ##[error]Error: Package deployment using ZIP Deploy failed. Refer logs for more details.
2019-02-21T13:25:07.8597592Z Successfully added release annotation to the Application Insight : timesheet-backend
2019-02-21T13:25:09.7921504Z Successfully updated deployment History at https://timesheet-backend.scm.azurewebsites.net/api/deployments/91550755507860
2019-02-21T13:25:09.7954513Z ##[section]Finishing: Deploy Azure App Service

@metin
Copy link

metin commented Mar 12, 2019 •
edited

Just FYI - I was having same problem with tomcat runtime. Java SE runtime works tho.

@AltarBeastiful
Copy link

Same problem on Node 10.14 deployment. Right now my solution is to do the npm install and build in post-deployment script.

2019-03-15T10:00:28.6009617Z Command: "/home/site/deployments/tools/deploy.sh"
2019-03-15T10:00:28.6010078Z Handling Basic Web Site deployment.
2019-03-15T10:00:28.6010454Z Kudu sync from: '/tmp/zipdeploy/extracted' to: '/home/site/wwwroot'
2019-03-15T10:00:28.6010711Z Copying file: '.dockerignore'
....
2019-03-15T10:00:28.6026397Z Copying file: 'dist/models/index.js'
2019-03-15T10:00:28.6026635Z Omitting next output lines...
2019-03-15T10:00:28.6026871Z Error: ENOENT: no such file or directory, utime '/home/site/wwwroot/node_modules/.bin/escodegen'
2019-03-15T10:00:28.6027124Z An error has occurred during web site deployment.
2019-03-15T10:00:28.6027354Z Kudu Sync failed
2019-03-15T10:00:28.6027580Z \n/opt/Kudu/Scripts/starter.sh "/home/site/deployments/tools/deploy.sh"
2019-03-15T10:00:28.6027824Z App container will begin restart within 10 seconds.
2019-03-15T10:00:28.6113580Z ##[error]Failed to deploy web package to App Service.
2019-03-15T10:00:28.6123485Z ##[error]Error: Package deployment using ZIP Deploy failed. Refer logs for more details.

@vincent1173
Copy link
Contributor

vincent1173 commented Mar 15, 2019 •
edited

@AltarBeastiful , Can you post the issue here for Zip deploy failures?

@AltarBeastiful
Copy link

Nevermind, tried again and it worked. Will post error on the correct repo if it happens again.

@AltarBeastiful
Copy link

It hapened again on different files of then node_modules,
opened an issue on kudu to track this: projectkudu/kudu#2946

@chtourou-youssef
Copy link

same problem here

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@SumiranAgg SumiranAgg

@kmkumaran kmkumaran

@chshrikh chshrikh

Labels
Area: AzureAppService Label to monitor Azure App Service issues Area: Release
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
10 participants
@metin @jdadojr @AltarBeastiful @egiray @sofipacifico @SumiranAgg @kmkumaran @chshrikh @vincent1173 @chtourou-youssef