Azure-pipelines-tasks: Azure App Service Deploy 4.* Error: "File not found in Kudu Service. script_result.txt"

[BenBrooksCin7]

Environment

• Environment: VSTS

• Agent: Hosted agent, queue name: "Hosted VS2017"

Issue Description

We have 2 existing deploys to 2 different Azure websites, each site also has another site in a Virtual application. As of around time 2018-07-10T23:30:00 the deployment to the root site was still working fine, but deployments to the Virtual application (which step is directly after) started failing. Neither definition nor site was updated around the time of the failure. There was another build around 2 hours earlier which completed just fine.

I'm guessing that around that time, change #7438 went live and I think the error is on line 63 as it uses a partially hard coded path which is then not used when the file is read on line 262.

We have since updated the deploy to use Azure App Service Deploy 3.* and it deploys without issue.

As part of this deploy step, a post deployment action inline script is executed. Unsure if this contributes to the above issue or not. There is also a post deployment action inline script on the previous step that deploys to the root site without issue.

Error logs

2018-07-10T23:33:27.2761084Z Executing given script on Kudu service.
2018-07-10T23:33:32.9258596Z ##[error]Error: Unable to run the script on Kudu Service. Error: Error: File not found in Kudu Service. script_result.txt

[vincent1173]

@BenBrooksCin7 , thanks for reporting the issue and identifying the cause.
It's a genuine issue and will be fixed in upcoming deployment.

[vincent1173]

The issue is fixed and the fix is available in all accounts.

[rand0me]

I'm still experiencing this issue while deploying Azure Function App with any post-deployment command

[vincent1173]

@rand0me , can you share the task version and the debug logs (set variable system.debug to true and requeue a release)?

[rand0me]

Yea, here it is:

2018-08-07T11:54:12.8098164Z ##[debug]Evaluating condition for step: 'Azure App Service Deploy: censored-next-linux'
2018-08-07T11:54:12.8101386Z ##[debug]Evaluating: succeeded()
2018-08-07T11:54:12.8102393Z ##[debug]Evaluating succeeded:
2018-08-07T11:54:12.8103703Z ##[debug]=> True
2018-08-07T11:54:12.8105262Z ##[debug]Result: True
2018-08-07T11:54:12.8107565Z ##[section]Starting: Azure App Service Deploy: censored-next-linux
2018-08-07T11:54:12.8130134Z ==============================================================================
2018-08-07T11:54:12.8130840Z Task         : Azure App Service Deploy
2018-08-07T11:54:12.8131698Z Description  : Update Azure WebApp Services On Windows, Web App On Linux with built-in images or docker containers, ASP.NET, .NET Core, PHP, Python or Node based Web applications, Function Apps, Mobile Apps, Api applications, Web Jobs using Web Deploy / Kudu REST APIs
2018-08-07T11:54:12.8132584Z Version      : 4.2.6
2018-08-07T11:54:12.8133083Z Author       : Microsoft Corporation
2018-08-07T11:54:12.8133731Z Help         : [More Information](https://aka.ms/azurermwebdeployreadme)
2018-08-07T11:54:12.8134731Z ==============================================================================
2018-08-07T11:54:13.4972835Z ##[debug]agent.workFolder=D:\vsts-agent\_work
2018-08-07T11:54:13.5068763Z ##[debug]loading inputs and endpoints
2018-08-07T11:54:13.5083628Z ##[debug]loading ENDPOINT_AUTH_d01e35ad-xxxx-xxxx-xxxx-6fa148125efd
2018-08-07T11:54:13.5114790Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_d01e35ad-xxxx-xxxx-xxxx-6fa148125efd_SERVICEPRINCIPALID
2018-08-07T11:54:13.5122776Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_d01e35ad-xxxx-xxxx-xxxx-6fa148125efd_SERVICEPRINCIPALKEY
2018-08-07T11:54:13.5128572Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_d01e35ad-xxxx-xxxx-xxxx-6fa148125efd_TENANTID
2018-08-07T11:54:13.5134280Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_SYSTEMVSSCONNECTION_ACCESSTOKEN
2018-08-07T11:54:13.5139789Z ##[debug]loading ENDPOINT_AUTH_SCHEME_d01e35ad-xxxx-xxxx-xxxx-6fa148125efd
2018-08-07T11:54:13.5145267Z ##[debug]loading ENDPOINT_AUTH_SCHEME_SYSTEMVSSCONNECTION
2018-08-07T11:54:13.5149714Z ##[debug]loading ENDPOINT_AUTH_SYSTEMVSSCONNECTION
2018-08-07T11:54:13.5163857Z ##[debug]loading INPUT_CONNECTEDSERVICENAME
2018-08-07T11:54:13.5171633Z ##[debug]loading INPUT_CONNECTIONTYPE
2018-08-07T11:54:13.5176152Z ##[debug]loading INPUT_DEPLOYMENTTYPE
2018-08-07T11:54:13.5181400Z ##[debug]loading INPUT_DEPLOYTOSLOTORASEFLAG
2018-08-07T11:54:13.5187695Z ##[debug]loading INPUT_EXCLUDEFILESFROMAPPDATAFLAG
2018-08-07T11:54:13.5194908Z ##[debug]loading INPUT_INLINESCRIPT
2018-08-07T11:54:13.5202871Z ##[debug]loading INPUT_PACKAGE
2018-08-07T11:54:13.5206992Z ##[debug]loading INPUT_PUBLISHPROFILEPATH
2018-08-07T11:54:13.5218897Z ##[debug]loading INPUT_REMOVEADDITIONALFILESFLAG
2018-08-07T11:54:13.5220155Z ##[debug]loading INPUT_RENAMEFILESFLAG
2018-08-07T11:54:13.5223702Z ##[debug]loading INPUT_RESOURCEGROUPNAME
2018-08-07T11:54:13.5231058Z ##[debug]loading INPUT_SCRIPTPATH
2018-08-07T11:54:13.5237317Z ##[debug]loading INPUT_SCRIPTTYPE
2018-08-07T11:54:13.5241544Z ##[debug]loading INPUT_SETPARAMETERSFILE
2018-08-07T11:54:13.5246686Z ##[debug]loading INPUT_SLOTNAME
2018-08-07T11:54:13.5254084Z ##[debug]loading INPUT_TAKEAPPOFFLINEFLAG
2018-08-07T11:54:13.5259343Z ##[debug]loading INPUT_USEWEBDEPLOY
2018-08-07T11:54:13.5265548Z ##[debug]loading INPUT_WEBAPPKIND
2018-08-07T11:54:13.5269856Z ##[debug]loading INPUT_WEBAPPNAME
2018-08-07T11:54:13.5275062Z ##[debug]loading INPUT_XMLTRANSFORMATION
2018-08-07T11:54:13.5280794Z ##[debug]loading INPUT_XMLVARIABLESUBSTITUTION
2018-08-07T11:54:13.5303043Z ##[debug]loaded 29
2018-08-07T11:54:14.4353424Z ##[debug]agent.proxyurl=undefined
2018-08-07T11:54:14.4355738Z ##[debug]VSTS_ARM_REST_IGNORE_SSL_ERRORS=undefined
2018-08-07T11:54:14.4357976Z ##[debug]AZURE_HTTP_USER_AGENT=VSTS_7ca298fe-xxxx-xxxx-xxxx-90a0ad2a198a_release_147_6182_15914_1
2018-08-07T11:54:14.5897542Z ##[debug]check path : D:\vsts-agent\_work\_tasks\AzureRmWebAppDeployment_497d490f-xxxx-xxxx-xxxx-48d9c1acdcb1\4.2.6\task.json
2018-08-07T11:54:14.5905867Z ##[debug]set resource file to: D:\vsts-agent\_work\_tasks\AzureRmWebAppDeployment_497d490f-xxxx-xxxx-xxxx-48d9c1acdcb1\4.2.6\task.json
2018-08-07T11:54:14.5908276Z ##[debug]system.culture=en-US
2018-08-07T11:54:14.6451256Z ##[debug]ConnectionType=AzureRM
2018-08-07T11:54:14.6457745Z ##[debug]WebAppKind=functionApp
2018-08-07T11:54:14.6464106Z ##[debug]DeployToSlotOrASEFlag=false
2018-08-07T11:54:14.6466455Z ##[debug]VirtualApplication=null
2018-08-07T11:54:14.6468567Z ##[debug]GenerateWebConfig=null
2018-08-07T11:54:14.6470468Z ##[debug]WebConfigParameters=null
2018-08-07T11:54:14.6475720Z ##[debug]XmlTransformation=false
2018-08-07T11:54:14.6478474Z ##[debug]JSONFiles=null
2018-08-07T11:54:14.6485135Z ##[debug]XmlVariableSubstitution=
2018-08-07T11:54:44.9783278Z Copying file: 'censored/sample.dat'
2018-08-07T11:54:44.9783850Z Copying file: 'censored/dist/Context.js'
2018-08-07T11:54:44.9785036Z Copying file: 'censored/dist/Context.js.map'
2018-08-07T11:54:44.9785610Z Copying file: 'censored/dist/Context.stub.js'
2018-08-07T11:54:44.9786194Z Copying file: 'censored/dist/Context.stub.js.map'
2018-08-07T11:54:44.9786734Z Copying file: 'censored/dist/index.js'
2018-08-07T11:54:44.9787289Z Copying file: 'censored/dist/index.js.map'
2018-08-07T11:54:44.9787814Z Copying file: 'censored/dist/main.js'
2018-08-07T11:54:44.9788336Z Copying file: 'censored/dist/main.js.map'
2018-08-07T11:54:44.9788898Z Copying file: 'censored/dist/main.spec.js'
2018-08-07T11:54:44.9789433Z Copying file: 'censored/dist/main.spec.js.map'
2018-08-07T11:54:44.9790023Z Copying file: 'censored/dist/common/config.dev.js'
2018-08-07T11:54:44.9790589Z Copying file: 'censored/dist/common/config.dev.js.map'
2018-08-07T11:54:44.9791354Z Copying file: 'censored/dist/common/config.js'
2018-08-07T11:54:44.9792117Z Copying file: 'censored/dist/common/config.js.map'
2018-08-07T11:54:44.9792797Z Copying file: 'censored/dist/common/config.prod.js'
2018-08-07T11:54:44.9793368Z Copying file: 'censored/dist/common/config.prod.js.map'
2018-08-07T11:54:44.9793960Z Copying file: 'censored/dist/lib/InhabitAPI.js'
2018-08-07T11:54:44.9794744Z Copying file: 'censored/dist/lib/InhabitAPI.js.map'
2018-08-07T11:54:44.9797203Z Copying file: 'censored/dist/lib/Insights.js'
2018-08-07T11:54:44.9798332Z Copying file: 'censored/dist/lib/Insights.js.map'
2018-08-07T11:54:44.9798935Z Copying file: 'censored/dist/lib/InsightsEvents.js'
2018-08-07T11:54:44.9799505Z Copying file: 'censored/dist/lib/InsightsEvents.js.map'
2018-08-07T11:54:44.9800093Z Copying file: 'censored/dist/lib/Logger.js'
2018-08-07T11:54:44.9800637Z Copying file: 'censored/dist/lib/Logger.js.map'
2018-08-07T11:54:44.9801465Z Copying file: 'censored/dist/lib/Timeout.js'
2018-08-07T11:54:44.9802079Z Copying file: 'censored/dist/lib/Timeout.js.map'
2018-08-07T11:54:44.9802700Z Copying file: 'censored/dist/lib/Wait.js'
2018-08-07T11:54:44.9803268Z Copying file: 'censored/dist/lib/Wait.js.map'
2018-08-07T11:54:44.9803813Z Copying file: 'censored/dist/lib/compose.js'
2018-08-07T11:54:44.9805530Z Copying file: 'censored/dist/lib/compose.js.map'
2018-08-07T11:54:44.9806188Z Copying file: 'censored/dist/lib/models/IAIMapping.js'
2018-08-07T11:54:44.9806814Z Copying file: 'censored/dist/lib/models/IAIMapping.js.map'
2018-08-07T11:54:44.9807414Z Copying file: 'censored/dist/lib/models/IBrowserTestRequest.js'
2018-08-07T11:54:44.9808063Z Copying file: 'censored/dist/lib/models/IBrowserTestRequest.js.map'
2018-08-07T11:54:44.9808672Z Copying file: 'censored/dist/lib/models/IBrowserTestResult.js'
2018-08-07T11:54:44.9809311Z Copying file: 'censored/dist/lib/models/IBrowserTestResult.js.map'
2018-08-07T11:54:44.9809903Z Copying file: 'censored/dist/lib/models/ICategory.js'
2018-08-07T11:54:44.9810619Z Copying file: 'censored/dist/lib/models/ICategory.js.map'
2018-08-07T11:54:44.9811848Z Copying file: 'censored/dist/lib/models/IEntity.js'
2018-08-07T11:54:44.9812521Z Copying file: 'censored/dist/lib/models/IEntity.js.map'
2018-08-07T11:54:44.9813137Z Copying file: 'censored/dist/lib/models/IFactiveAIConfigurationModel.js'
2018-08-07T11:54:44.9813810Z Copying file: 'censored/dist/lib/models/IFactiveAIConfigurationModel.js.map'
2018-08-07T11:54:14.6491738Z ##[debug]TakeAppOfflineFlag=true
2018-08-07T11:54:14.6499673Z ##[debug]RenameFilesFlag=false
2018-08-07T11:54:14.6501782Z ##[debug]AdditionalArguments=null
2018-08-07T11:54:44.9783278Z Copying file: 'censored/sample.dat'
2018-08-07T11:54:44.9783850Z Copying file: 'censored/dist/Context.js'
2018-08-07T11:54:44.9785036Z Copying file: 'censored/dist/Context.js.map'
2018-08-07T11:54:44.9785610Z Copying file: 'censored/dist/Context.stub.js'
2018-08-07T11:54:44.9786194Z Copying file: 'censored/dist/Context.stub.js.map'
2018-08-07T11:54:44.9786734Z Copying file: 'censored/dist/index.js'
2018-08-07T11:54:44.9787289Z Copying file: 'censored/dist/index.js.map'
2018-08-07T11:54:44.9787814Z Copying file: 'censored/dist/main.js'
2018-08-07T11:54:44.9788336Z Copying file: 'censored/dist/main.js.map'
2018-08-07T11:54:44.9788898Z Copying file: 'censored/dist/main.spec.js'
2018-08-07T11:54:44.9789433Z Copying file: 'censored/dist/main.spec.js.map'
2018-08-07T11:54:44.9790023Z Copying file: 'censored/dist/common/config.dev.js'
2018-08-07T11:54:44.9790589Z Copying file: 'censored/dist/common/config.dev.js.map'
2018-08-07T11:54:44.9791354Z Copying file: 'censored/dist/common/config.js'
2018-08-07T11:54:44.9792117Z Copying file: 'censored/dist/common/config.js.map'
2018-08-07T11:54:44.9792797Z Copying file: 'censored/dist/common/config.prod.js'
2018-08-07T11:54:44.9793368Z Copying file: 'censored/dist/common/config.prod.js.map'
2018-08-07T11:54:44.9793960Z Copying file: 'censored/dist/lib/InhabitAPI.js'
2018-08-07T11:54:44.9794744Z Copying file: 'censored/dist/lib/InhabitAPI.js.map'
2018-08-07T11:54:44.9797203Z Copying file: 'censored/dist/lib/Insights.js'
2018-08-07T11:54:44.9798332Z Copying file: 'censored/dist/lib/Insights.js.map'
2018-08-07T11:54:44.9798935Z Copying file: 'censored/dist/lib/InsightsEvents.js'
2018-08-07T11:54:44.9799505Z Copying file: 'censored/dist/lib/InsightsEvents.js.map'
2018-08-07T11:54:44.9800093Z Copying file: 'censored/dist/lib/Logger.js'
2018-08-07T11:54:44.9800637Z Copying file: 'censored/dist/lib/Logger.js.map'
2018-08-07T11:54:44.9801465Z Copying file: 'censored/dist/lib/Timeout.js'
2018-08-07T11:54:44.9802079Z Copying file: 'censored/dist/lib/Timeout.js.map'
2018-08-07T11:54:44.9802700Z Copying file: 'censored/dist/lib/Wait.js'
2018-08-07T11:54:44.9803268Z Copying file: 'censored/dist/lib/Wait.js.map'
2018-08-07T11:54:44.9803813Z Copying file: 'censored/dist/lib/compose.js'
2018-08-07T11:54:44.9805530Z Copying file: 'censored/dist/lib/compose.js.map'
2018-08-07T11:54:44.9806188Z Copying file: 'censored/dist/lib/models/IAIMapping.js'
2018-08-07T11:54:44.9806814Z Copying file: 'censored/dist/lib/models/IAIMapping.js.map'
2018-08-07T11:54:44.9807414Z Copying file: 'censored/dist/lib/models/IBrowserTestRequest.js'
2018-08-07T11:54:44.9808063Z Copying file: 'censored/dist/lib/models/IBrowserTestRequest.js.map'
2018-08-07T11:54:44.9808672Z Copying file: 'censored/dist/lib/models/IBrowserTestResult.js'
2018-08-07T11:54:44.9809311Z Copying file: 'censored/dist/lib/models/IBrowserTestResult.js.map'
2018-08-07T11:54:44.9809903Z Copying file: 'censored/dist/lib/models/ICategory.js'
2018-08-07T11:54:44.9810619Z Copying file: 'censored/dist/lib/models/ICategory.js.map'
2018-08-07T11:54:44.9811848Z Copying file: 'censored/dist/lib/models/IEntity.js'
2018-08-07T11:54:44.9812521Z Copying file: 'censored/dist/lib/models/IEntity.js.map'
2018-08-07T11:54:44.9813137Z Copying file: 'censored/dist/lib/models/IFactiveAIConfigurationModel.js'
2018-08-07T11:54:44.9813810Z Copying file: 'censored/dist/lib/models/IFactiveAIConfigurationModel.js.map'
2018-08-07T11:54:14.6509193Z ##[debug]ScriptType=Inline Script
2018-08-07T11:54:14.6517690Z ##[debug]InlineScript=:: You can provide your deployment commands here. One command per line.
node -v
npm -v
npm install --production
2018-08-07T11:54:14.6526901Z ##[debug]ScriptPath=D:\vsts-agent\_work\r145\a
2018-08-07T11:54:14.6528319Z ##[debug]DockerNamespace=null
2018-08-07T11:54:14.6529211Z ##[debug]AppSettings=null
2018-08-07T11:54:14.6531429Z ##[debug]StartupCommand=null
2018-08-07T11:54:14.6532835Z ##[debug]ConfigurationSettings=null
2018-08-07T11:54:14.6538431Z ##[debug]ConnectedServiceName=d01e35ad-xxxx-xxxx-xxxx-6fa148125efd
2018-08-07T11:54:14.6542718Z ##[debug]WebAppName=censored-next-linux
2018-08-07T11:54:14.6957021Z ##[debug]Processed: ##vso[telemetry.publish area=TaskEndpointId;feature=AzureRmWebAppDeployment]{"endpointId":"d01e35ad-xxxx-xxxx-xxxx-6fa148125efd"}
2018-08-07T11:54:14.6960464Z ##[debug]Package=D:\vsts-agent\_work\r145\a\xxxxxxx-xxxxxxx-ai-censored-next\drop
2018-08-07T11:54:14.6961695Z ##[debug]Finding files matching input: D:\vsts-agent\_work\r145\a\xxxxxxx-xxxxxxx-ai-censored-next\drop
2018-08-07T11:54:14.6962653Z ##[debug]UseWebDeploy=false
2018-08-07T11:54:14.6963507Z ##[debug]Is the package an msdeploy package : false
2018-08-07T11:54:14.6964354Z ##[debug]Is this a war file : false
2018-08-07T11:54:14.6965128Z ##[debug]Predeployment Step Started
2018-08-07T11:54:14.6966058Z ##[debug]d01e35ad-xxxx-xxxx-xxxx-6fa148125efd data subscriptionid = 6a1f4abf-xxxx-xxxx-xxxx-c4a7274ee43d
2018-08-07T11:54:14.6967075Z ##[debug]d01e35ad-xxxx-xxxx-xxxx-6fa148125efd data subscriptionname = Production - Pay-As-You-Go
2018-08-07T11:54:14.6968866Z ##[debug]d01e35ad-xxxx-xxxx-xxxx-6fa148125efd auth param serviceprincipalid = ***
2018-08-07T11:54:14.6970142Z ##[debug]d01e35ad-xxxx-xxxx-xxxx-6fa148125efd auth param serviceprincipalkey = ***
2018-08-07T11:54:14.6971179Z ##[debug]d01e35ad-xxxx-xxxx-xxxx-6fa148125efd data environmentAuthorityUrl = https://login.windows.net/
2018-08-07T11:54:14.6972283Z ##[debug]d01e35ad-xxxx-xxxx-xxxx-6fa148125efd auth param tenantid = ***
2018-08-07T11:54:14.6973284Z ##[debug]d01e35ad-xxxx-xxxx-xxxx-6fa148125efd=https://management.azure.com/
2018-08-07T11:54:14.6974226Z ##[debug]d01e35ad-xxxx-xxxx-xxxx-6fa148125efd data environment = AzureCloud
2018-08-07T11:54:14.6975166Z ##[debug]d01e35ad-xxxx-xxxx-xxxx-6fa148125efd auth scheme = ServicePrincipal
2018-08-07T11:54:14.6976071Z ##[debug]d01e35ad-xxxx-xxxx-xxxx-6fa148125efd data msiclientId = undefined
2018-08-07T11:54:14.6977094Z ##[debug]d01e35ad-xxxx-xxxx-xxxx-6fa148125efd data activeDirectoryServiceEndpointResourceId = https://management.core.windows.net/
2018-08-07T11:54:14.6978162Z Got service connection details for Azure App Service:'censored-next-linux'
2018-08-07T11:54:14.7167878Z ##[debug][POST]https://login.windows.net/***/oauth2/token/
2018-08-07T11:54:15.0553500Z ##[debug][GET]https://management.azure.com/subscriptions/6a1f4abf-xxxx-xxxx-xxxx-c4a7274ee43d/resources?$filter=resourceType EQ 'Microsoft.Web%2FSites' AND name EQ 'censored-next-linux'&api-version=2016-07-01
2018-08-07T11:54:16.1105729Z ##[debug]Resource Group: censored-next-linux
2018-08-07T11:54:16.1155801Z ##[debug][POST]https://management.azure.com/subscriptions/6a1f4abf-xxxx-xxxx-xxxx-c4a7274ee43d/resourceGroups/censored-next-linux/providers/Microsoft.Web/sites/censored-next-linux/config/publishingcredentials/list?api-version=2016-08-01
2018-08-07T11:54:16.6181336Z ##[debug]set AZURE_APP_SERVICE_KUDU_production_PASSWORD=********
2018-08-07T11:54:16.6222241Z ##[debug]Processed: ##vso[task.setvariable variable=AZURE_APP_SERVICE_KUDU_production_PASSWORD;issecret=true;]***
2018-08-07T11:54:16.6224622Z ##[debug][POST]https://management.azure.com/subscriptions/6a1f4abf-xxxx-xxxx-xxxx-c4a7274ee43d/resourceGroups/censored-next-linux/providers/Microsoft.Web/sites/censored-next-linux/publishxml?api-version=2016-08-01
2018-08-07T11:54:17.2241098Z App Service Application URL: http://censored-next-linux.azurewebsites.net
2018-08-07T11:54:17.2243703Z ##[debug]set AppServiceApplicationUrl=http://censored-next-linux.azurewebsites.net
2018-08-07T11:54:17.2354245Z ##[debug]Processed: ##vso[task.setvariable variable=AppServiceApplicationUrl;issecret=false;]http://censored-next-linux.azurewebsites.net
2018-08-07T11:54:17.2356096Z ##[debug]Deployment Step Started
2018-08-07T11:54:17.2357337Z ##[debug]File Tranformation not enabled
2018-08-07T11:54:17.2358280Z ##[debug]Initiated deployment via kudu service for webapp package : 
2018-08-07T11:54:17.2358955Z Updating App Service Application settings. Data: {"WEBSITE_RUN_FROM_ZIP":"0"}
2018-08-07T11:54:17.2360484Z ##[debug][POST]https://management.azure.com/subscriptions/6a1f4abf-xxxx-xxxx-xxxx-c4a7274ee43d/resourceGroups/censored-next-linux/providers/Microsoft.Web/sites/censored-next-linux/config/appsettings/list?api-version=2016-08-01
2018-08-07T11:54:17.8020334Z Updated App Service Application settings and Kudu Application settings.
2018-08-07T11:54:17.8038084Z Package deployment using ZIP Deploy initiated.
2018-08-07T11:54:17.8044615Z ##[debug]AGENT.TEMPDIRECTORY=D:\vsts-agent\_work\_temp
2018-08-07T11:54:17.8064913Z ##[debug]Archiving D:\vsts-agent\_work\r145\a\xxxxxxx-xxxxxxx-ai-censored-next\drop to D:\vsts-agent\_work\_temp\temp_web_package_31604933419411463.zip
2018-08-07T11:54:18.9296460Z ##[debug]Successfully created archive D:\vsts-agent\_work\_temp\temp_web_package_31604933419411463.zip
2018-08-07T11:54:18.9303565Z ##[debug]Compressed folder D:\vsts-agent\_work\_temp\temp_web_package_31604933419411463.zip into zip : D:\vsts-agent\_work\_temp\temp_web_package_31604933419411463.zip
2018-08-07T11:54:18.9312502Z ##[debug]Trying to enable app offline mode.
2018-08-07T11:54:18.9313739Z ##[debug]AGENT.TEMPDIRECTORY=D:\vsts-agent\_work\_temp
2018-08-07T11:54:18.9366210Z ##[debug][PUT]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/vfs/site/wwwroot/app_offline.htm
2018-08-07T11:54:19.8416267Z ##[debug]uploadFile. Data: {"statusCode":200,"statusMessage":"OK","headers":{"server":"Apache/2.4.10 (Debian)","set-cookie":["ARRAffinity=63be0527b865f856b484dc6c55de34972eeaf17077dacccb9fa11d7e01640823;Path=/;HttpOnly;Domain=censored-next-linux.scm.azurewebsites.net"],"date":"Tue, 07 Aug 2018 11:54:19 GMT","connection":"close","content-length":"0"}}
2018-08-07T11:54:19.8418278Z ##[debug]App Offline mode enabled.
2018-08-07T11:54:19.8419218Z ##[debug]Wait for 5 seconds for app_offline to take effect
2018-08-07T11:54:24.8588460Z ##[debug][POST]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/zipdeploy?isAsync=true&deployer=VSTS_ZIP_DEPLOY
2018-08-07T11:54:26.7987356Z ##[debug]ZIP Deploy response: {"statusCode":202,"statusMessage":"Accepted","headers":{"cache-control":"no-cache","pragma":"no-cache","content-type":"text/html","expires":"-1","location":"https://censored-next-linux.scm.azurewebsites.net/api/deployments/latest?deployer=VSTS_ZIP_DEPLOY&time=2018-08-07_11-54-25Z","server":"Apache/2.4.10 (Debian)","x-aspnet-version":"4.0.30319","set-cookie":["ARRAffinity=63be0527b865f856b484dc6c55de34972eeaf17077dacccb9fa11d7e01640823;Path=/;HttpOnly;Domain=censored-next-linux.scm.azurewebsites.net"],"date":"Tue, 07 Aug 2018 11:54:25 GMT","connection":"close","content-length":"0"}}
2018-08-07T11:54:26.7990902Z ##[debug]Polling for ZIP Deploy URL: https://censored-next-linux.scm.azurewebsites.net/api/deployments/latest?deployer=VSTS_ZIP_DEPLOY&time=2018-08-07_11-54-25Z
2018-08-07T11:54:26.7999172Z ##[debug][GET]https://censored-next-linux.scm.azurewebsites.net/api/deployments/latest?deployer=VSTS_ZIP_DEPLOY&time=2018-08-07_11-54-25Z
2018-08-07T11:54:28.7760869Z ##[debug]POLL URL RESULT: {"id":"temp-0f3a9582","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-08-07T11:54:25.716208Z","start_time":"2018-08-07T11:54:25.716208Z","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":"censored-next-linux"}
2018-08-07T11:54:28.7763643Z ##[debug]Deployment status: 0 'Receiving changes.'. retry after 5 seconds
2018-08-07T11:54:33.7770674Z ##[debug][GET]https://censored-next-linux.scm.azurewebsites.net/api/deployments/latest?deployer=VSTS_ZIP_DEPLOY&time=2018-08-07_11-54-25Z
2018-08-07T11:54:35.7915032Z ##[debug]POLL URL RESULT: {"id":"ed4ddcf67f5448ff9350d1e0c7c0a2c5","status":1,"status_text":"Building and Deploying 'ed4ddcf67f5448ff9350d1e0c7c0a2c5'.","author_email":"N/A","author":"N/A","deployer":"VSTS_ZIP_DEPLOY","message":"Created via a push deployment","progress":"Running deployment command...","received_time":"2018-08-07T11:54:28.457103Z","start_time":"2018-08-07T11:54:28.95769Z","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":"censored-next-linux"}
2018-08-07T11:54:35.7918571Z ##[debug]Deployment status: 1 'Building and Deploying 'ed4ddcf67f5448ff9350d1e0c7c0a2c5'.'. retry after 5 seconds
2018-08-07T11:54:40.7953712Z ##[debug][GET]https://censored-next-linux.scm.azurewebsites.net/api/deployments/latest?deployer=VSTS_ZIP_DEPLOY&time=2018-08-07_11-54-25Z
2018-08-07T11:54:41.8314010Z ##[debug]POLL URL RESULT: {"id":"ed4ddcf67f5448ff9350d1e0c7c0a2c5","status":4,"status_text":"","author_email":"N/A","author":"N/A","deployer":"VSTS_ZIP_DEPLOY","message":"Created via a push deployment","progress":"","received_time":"2018-08-07T11:54:28.457103Z","start_time":"2018-08-07T11:54:28.95769Z","end_time":"2018-08-07T11:54:35.961987Z","last_success_end_time":"2018-08-07T11:54:35.961987Z","complete":true,"active":true,"is_temp":false,"is_readonly":true,"url":"https://censored-next-linux.scm.azurewebsites.net/api/deployments/latest","log_url":"https://censored-next-linux.scm.azurewebsites.net/api/deployments/latest/log","site_name":"censored-next-linux"}
2018-08-07T11:54:41.8330119Z ##[debug][GET]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/deployments/ed4ddcf67f5448ff9350d1e0c7c0a2c5
2018-08-07T11:54:42.4637306Z ##[debug]getDeploymentDetails. Data: {"statusCode":200,"statusMessage":"OK","headers":{"cache-control":"no-cache","pragma":"no-cache","content-length":"694","content-type":"application/json; charset=utf-8","expires":"-1","server":"Apache/2.4.10 (Debian)","x-ms-request-id":"899677da-e567-4803-b54a-b67a9d5483f2","x-aspnet-version":"4.0.30319","set-cookie":["ARRAffinity=63be0527b865f856b484dc6c55de34972eeaf17077dacccb9fa11d7e01640823;Path=/;HttpOnly;Domain=censored-next-linux.scm.azurewebsites.net"],"date":"Tue, 07 Aug 2018 11:54:41 GMT","connection":"close"},"body":{"id":"ed4ddcf67f5448ff9350d1e0c7c0a2c5","status":4,"status_text":"","author_email":"N/A","author":"N/A","deployer":"VSTS_ZIP_DEPLOY","message":"Created via a push deployment","progress":"","received_time":"2018-08-07T11:54:28.457103Z","start_time":"2018-08-07T11:54:28.95769Z","end_time":"2018-08-07T11:54:35.961987Z","last_success_end_time":"2018-08-07T11:54:35.961987Z","complete":true,"active":true,"is_temp":false,"is_readonly":true,"url":"https://censored-next-linux.scm.azurewebsites.net/api/deployments/ed4ddcf67f5448ff9350d1e0c7c0a2c5","log_url":"https://censored-next-linux.scm.azurewebsites.net/api/deployments/ed4ddcf67f5448ff9350d1e0c7c0a2c5/log","site_name":"censored-next-linux"}}
2018-08-07T11:54:42.4645271Z ##[debug]logs from ZIP deploy: https://censored-next-linux.scm.azurewebsites.net/api/deployments/ed4ddcf67f5448ff9350d1e0c7c0a2c5/log
2018-08-07T11:54:42.4647583Z ##[debug]system.debug=true
2018-08-07T11:54:42.4649534Z ##[debug]system.debug=true
2018-08-07T11:54:42.4661974Z ##[debug][GET]https://censored-next-linux.scm.azurewebsites.net/api/deployments/ed4ddcf67f5448ff9350d1e0c7c0a2c5/log
2018-08-07T11:54:43.4835043Z ##[debug]getDeploymentLogs. Data: {"statusCode":200,"statusMessage":"OK","headers":{"cache-control":"no-cache","pragma":"no-cache","content-length":"1406","content-type":"application/json; charset=utf-8","expires":"-1","server":"Apache/2.4.10 (Debian)","x-ms-request-id":"6a22ceb3-a863-403d-9a6b-72caf98bfe96","x-aspnet-version":"4.0.30319","set-cookie":["ARRAffinity=63be0527b865f856b484dc6c55de34972eeaf17077dacccb9fa11d7e01640823;Path=/;HttpOnly;Domain=censored-next-linux.scm.azurewebsites.net"],"date":"Tue, 07 Aug 2018 11:54:42 GMT","connection":"close"},"body":[{"log_time":"2018-08-07T11:54:28.755744Z","id":"99aa5fbb-6efa-4887-be0b-82b6d8e8b76e","message":"Updating submodules.","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:28.923436Z","id":"8ae3039f-c351-44ec-9d2b-c122ba12aeca","message":"Preparing deployment for commit id 'ed4ddcf67f'.","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:29.359962Z","id":"624686e9-31f6-4357-9aae-f7fc1f6a5d16","message":"Generating deployment script.","type":0,"details_url":"https://censored-next-linux.scm.azurewebsites.net/api/deployments/ed4ddcf67f5448ff9350d1e0c7c0a2c5/log/624686e9-31f6-4357-9aae-f7fc1f6a5d16"},{"log_time":"2018-08-07T11:54:30.094601Z","id":"446ef98d-d850-4ab4-8634-f08d9a0faa38","message":"Running deployment command...","type":0,"details_url":"https://censored-next-linux.scm.azurewebsites.net/api/deployments/ed4ddcf67f5448ff9350d1e0c7c0a2c5/log/446ef98d-d850-4ab4-8634-f08d9a0faa38"},{"log_time":"2018-08-07T11:54:35.605854Z","id":"f2286fd7-734d-4307-a983-14905217d735","message":"Running post deployment command(s)...","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:35.916328Z","id":"697e85c4-0533-45e2-9317-5ea4e524f396","message":"Deployment successful.","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:36.41612Z","id":"5c05a7fa-fe2f-4cb0-a866-6da5e186f848","message":"App container will begin restart within 10 seconds.","type":0,"details_url":null}]}
2018-08-07T11:54:43.4840533Z Updating submodules.
2018-08-07T11:54:43.4841194Z Preparing deployment for commit id 'ed4ddcf67f'.
2018-08-07T11:54:43.4841775Z Generating deployment script.
2018-08-07T11:54:43.4842944Z ##[debug][GET]https://censored-next-linux.scm.azurewebsites.net/api/deployments/ed4ddcf67f5448ff9350d1e0c7c0a2c5/log/624686e9-31f6-4357-9aae-f7fc1f6a5d16
2018-08-07T11:54:44.2333698Z ##[debug]getDeploymentLogs. Data: {"statusCode":200,"statusMessage":"OK","headers":{"cache-control":"no-cache","pragma":"no-cache","content-length":"293","content-type":"application/json; charset=utf-8","expires":"-1","server":"Apache/2.4.10 (Debian)","x-ms-request-id":"821ce4b3-8345-4aeb-8141-0a7a9cb06e07","x-aspnet-version":"4.0.30319","set-cookie":["ARRAffinity=63be0527b865f856b484dc6c55de34972eeaf17077dacccb9fa11d7e01640823;Path=/;HttpOnly;Domain=censored-next-linux.scm.azurewebsites.net"],"date":"Tue, 07 Aug 2018 11:54:43 GMT","connection":"close"},"body":[{"log_time":"2018-08-07T11:54:29.988622Z","id":"","message":"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\"').","type":0,"details_url":null}]}
2018-08-07T11:54:44.2338744Z 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-08-07T11:54:44.2339653Z Running deployment command...
2018-08-07T11:54:44.2353833Z ##[debug][GET]https://censored-next-linux.scm.azurewebsites.net/api/deployments/ed4ddcf67f5448ff9350d1e0c7c0a2c5/log/446ef98d-d850-4ab4-8634-f08d9a0faa38
2018-08-07T11:54:44.9759394Z ##[debug]getDeploymentLogs. Data: {"statusCode":200,"statusMessage":"OK","headers":{"cache-control":"no-cache","pragma":"no-cache","content-length":"7508","content-type":"application/json; charset=utf-8","expires":"-1","server":"Apache/2.4.10 (Debian)","x-ms-request-id":"28bdcc82-e989-4194-a05d-2ad5be0ff27e","x-aspnet-version":"4.0.30319","set-cookie":["ARRAffinity=63be0527b865f856b484dc6c55de34972eeaf17077dacccb9fa11d7e01640823;Path=/;HttpOnly;Domain=censored-next-linux.scm.azurewebsites.net"],"date":"Tue, 07 Aug 2018 11:54:44 GMT","connection":"close"},"body":[{"log_time":"2018-08-07T11:54:30.109358Z","id":"","message":"Command: \"/home/site/deployments/tools/deploy.sh\"","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:31.820045Z","id":"","message":"Handling Basic Web Site deployment.","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:32.815567Z","id":"","message":"Kudu sync from: '/tmp/zipdeploy/extracted' to: '/home/site/wwwroot'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:32.858398Z","id":"","message":"Copying file: '.gitignore'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:32.908993Z","id":"","message":"Copying file: 'host.json'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:32.940032Z","id":"","message":"Copying file: 'package.json'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:32.974731Z","id":"","message":"Copying file: 'censored/function.json'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.008908Z","id":"","message":"Copying file: 'censored/index.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.045621Z","id":"","message":"Copying file: 'censored/readme.md'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.07816Z","id":"","message":"Copying file: 'censored/sample.dat'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.106571Z","id":"","message":"Copying file: 'censored/dist/Context.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.128425Z","id":"","message":"Copying file: 'censored/dist/Context.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.150508Z","id":"","message":"Copying file: 'censored/dist/Context.stub.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.183858Z","id":"","message":"Copying file: 'censored/dist/Context.stub.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.212506Z","id":"","message":"Copying file: 'censored/dist/index.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.236218Z","id":"","message":"Copying file: 'censored/dist/index.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.27044Z","id":"","message":"Copying file: 'censored/dist/main.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.309222Z","id":"","message":"Copying file: 'censored/dist/main.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.365984Z","id":"","message":"Copying file: 'censored/dist/main.spec.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.411062Z","id":"","message":"Copying file: 'censored/dist/main.spec.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.438552Z","id":"","message":"Copying file: 'censored/dist/common/config.dev.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.463883Z","id":"","message":"Copying file: 'censored/dist/common/config.dev.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.491888Z","id":"","message":"Copying file: 'censored/dist/common/config.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.518752Z","id":"","message":"Copying file: 'censored/dist/common/config.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.552634Z","id":"","message":"Copying file: 'censored/dist/common/config.prod.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.600815Z","id":"","message":"Copying file: 'censored/dist/common/config.prod.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.632968Z","id":"","message":"Copying file: 'censored/dist/lib/InhabitAPI.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.653927Z","id":"","message":"Copying file: 'censored/dist/lib/InhabitAPI.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.678483Z","id":"","message":"Copying file: 'censored/dist/lib/Insights.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.700893Z","id":"","message":"Copying file: 'censored/dist/lib/Insights.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.733517Z","id":"","message":"Copying file: 'censored/dist/lib/InsightsEvents.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.759533Z","id":"","message":"Copying file: 'censored/dist/lib/InsightsEvents.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.791788Z","id":"","message":"Copying file: 'censored/dist/lib/Logger.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.82408Z","id":"","message":"Copying file: 'censored/dist/lib/Logger.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.851981Z","id":"","message":"Copying file: 'censored/dist/lib/Timeout.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.874063Z","id":"","message":"Copying file: 'censored/dist/lib/Timeout.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.902469Z","id":"","message":"Copying file: 'censored/dist/lib/Wait.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.937331Z","id":"","message":"Copying file: 'censored/dist/lib/Wait.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.96748Z","id":"","message":"Copying file: 'censored/dist/lib/compose.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:33.994869Z","id":"","message":"Copying file: 'censored/dist/lib/compose.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:34.02058Z","id":"","message":"Copying file: 'censored/dist/lib/models/IAIMapping.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:34.042222Z","id":"","message":"Copying file: 'censored/dist/lib/models/IAIMapping.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:34.092295Z","id":"","message":"Copying file: 'censored/dist/lib/models/IBrowserTestRequest.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:34.122334Z","id":"","message":"Copying file: 'censored/dist/lib/models/IBrowserTestRequest.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:34.148997Z","id":"","message":"Copying file: 'censored/dist/lib/models/IBrowserTestResult.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:34.18023Z","id":"","message":"Copying file: 'censored/dist/lib/models/IBrowserTestResult.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:34.204019Z","id":"","message":"Copying file: 'censored/dist/lib/models/ICategory.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:34.231975Z","id":"","message":"Copying file: 'censored/dist/lib/models/ICategory.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:34.259718Z","id":"","message":"Copying file: 'censored/dist/lib/models/IEntity.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:34.295035Z","id":"","message":"Copying file: 'censored/dist/lib/models/IEntity.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:34.343934Z","id":"","message":"Copying file: 'censored/dist/lib/models/IFactiveAIConfigurationModel.js'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:34.378338Z","id":"","message":"Copying file: 'censored/dist/lib/models/IFactiveAIConfigurationModel.js.map'","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:34.402669Z","id":"","message":"Omitting next output lines...","type":0,"details_url":null},{"log_time":"2018-08-07T11:54:35.391905Z","id":"","message":"Finished successfully.","type":0,"details_url":null}]}
2018-08-07T11:54:44.9778077Z Command: "/home/site/deployments/tools/deploy.sh"
2018-08-07T11:54:44.9778707Z Handling Basic Web Site deployment.
2018-08-07T11:54:44.9779286Z Kudu sync from: '/tmp/zipdeploy/extracted' to: '/home/site/wwwroot'
2018-08-07T11:54:44.9779874Z Copying file: '.gitignore'
2018-08-07T11:54:44.9780383Z Copying file: 'host.json'
2018-08-07T11:54:44.9780862Z Copying file: 'package.json'
2018-08-07T11:54:44.9781645Z Copying file: 'censored/function.json'
2018-08-07T11:54:44.9782230Z Copying file: 'censored/index.js'
2018-08-07T11:54:44.9782740Z Copying file: 'censored/readme.md'
2018-08-07T11:54:44.9814643Z Omitting next output lines...
2018-08-07T11:54:44.9815192Z Finished successfully.
2018-08-07T11:54:44.9815687Z Running post deployment command(s)...
2018-08-07T11:54:44.9816204Z Deployment successful.
2018-08-07T11:54:44.9816721Z App container will begin restart within 10 seconds.
2018-08-07T11:54:44.9817853Z ##[debug]Trying to disable app offline mode.
2018-08-07T11:54:44.9833888Z ##[debug][DELETE]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/vfs/site/wwwroot/app_offline.htm
2018-08-07T11:54:45.5870129Z ##[debug]deleteFile. Data: {"statusCode":200,"statusMessage":"OK","headers":{"cache-control":"no-cache","pragma":"no-cache","content-type":"text/html","expires":"-1","server":"Apache/2.4.10 (Debian)","x-ms-request-id":"6005b7e6-a7ba-4e23-b603-26720a30d3b5","x-aspnet-version":"4.0.30319","set-cookie":["ARRAffinity=63be0527b865f856b484dc6c55de34972eeaf17077dacccb9fa11d7e01640823;Path=/;HttpOnly;Domain=censored-next-linux.scm.azurewebsites.net"],"date":"Tue, 07 Aug 2018 11:54:44 GMT","connection":"close","content-length":"0"}}
2018-08-07T11:54:45.5873548Z ##[debug]App Offline mode disabled.
2018-08-07T11:54:45.5874236Z Successfully deployed web package to App Service.
2018-08-07T11:54:45.5894704Z ##[debug]build.buildUri=vstfs:///Build/Build/44418
2018-08-07T11:54:45.5896001Z ##[debug]release.releaseUri=vstfs:///ReleaseManagement/Release/6182
2018-08-07T11:54:45.5897002Z ##[debug]build.buildId=44418
2018-08-07T11:54:45.5897953Z ##[debug]release.releaseId=6182
2018-08-07T11:54:45.5898820Z ##[debug]build.buildNumber=20180806.2
2018-08-07T11:54:45.5899735Z ##[debug]release.releaseName=Release-20
2018-08-07T11:54:45.5936842Z ##[debug]system.TeamFoundationCollectionUri=https://arkadiumarena.visualstudio.com/
2018-08-07T11:54:45.5938953Z ##[debug]system.teamProjectId=8d173395-e7e1-4a2b-9797-06e2a6338699
2018-08-07T11:54:45.5940492Z ##[debug]build.sourceVersion=717626cae293c501130925152fa26590f04c84e4
2018-08-07T11:54:45.5942012Z ##[debug]build.repository.name=xxxxxxx-xxxxxxx-ai-censored
2018-08-07T11:54:45.5943642Z ##[debug]build.repository.provider=TfsGit
2018-08-07T11:54:45.5945170Z ##[debug]Trying to enable app offline mode.
2018-08-07T11:54:45.5946505Z ##[debug]AGENT.TEMPDIRECTORY=D:\vsts-agent\_work\_temp
2018-08-07T11:54:45.5985734Z ##[debug][PUT]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/vfs/site/wwwroot/app_offline.htm
2018-08-07T11:54:46.1575088Z ##[debug]uploadFile. Data: {"statusCode":200,"statusMessage":"OK","headers":{"server":"Apache/2.4.10 (Debian)","set-cookie":["ARRAffinity=63be0527b865f856b484dc6c55de34972eeaf17077dacccb9fa11d7e01640823;Path=/;HttpOnly;Domain=censored-next-linux.scm.azurewebsites.net"],"date":"Tue, 07 Aug 2018 11:54:45 GMT","connection":"close","content-length":"0"}}
2018-08-07T11:54:46.1577052Z ##[debug]App Offline mode enabled.
2018-08-07T11:54:46.1580904Z ##[debug]creating kuduPostDeploymentScript_local file
2018-08-07T11:54:46.1582037Z ##[debug]AGENT.TEMPDIRECTORY=D:\vsts-agent\_work\_temp
2018-08-07T11:54:46.1708507Z ##[debug]Created temporary script file : D:\vsts-agent\_work\_temp\kuduPostDeploymentScript_local.cmd
2018-08-07T11:54:46.1720392Z ##[debug][PUT]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/vfs/site/VSTS_PostDeployment_61821533642885586/mainCmdFile.cmd
2018-08-07T11:54:46.6713142Z ##[debug]uploadFile. Data: {"statusCode":200,"statusMessage":"OK","headers":{"server":"Apache/2.4.10 (Debian)","set-cookie":["ARRAffinity=63be0527b865f856b484dc6c55de34972eeaf17077dacccb9fa11d7e01640823;Path=/;HttpOnly;Domain=censored-next-linux.scm.azurewebsites.net"],"date":"Tue, 07 Aug 2018 11:54:45 GMT","connection":"close","content-length":"0"}}
2018-08-07T11:54:46.6720883Z ##[debug][PUT]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/vfs/site/VSTS_PostDeployment_61821533642885586/kuduPostDeploymentScript.cmd
2018-08-07T11:54:47.3328123Z ##[debug]uploadFile. Data: {"statusCode":200,"statusMessage":"OK","headers":{"server":"Apache/2.4.10 (Debian)","set-cookie":["ARRAffinity=63be0527b865f856b484dc6c55de34972eeaf17077dacccb9fa11d7e01640823;Path=/;HttpOnly;Domain=censored-next-linux.scm.azurewebsites.net"],"date":"Tue, 07 Aug 2018 11:54:46 GMT","connection":"close","content-length":"0"}}
2018-08-07T11:54:47.3332625Z Executing given script on Kudu service.
2018-08-07T11:54:47.3347881Z ##[debug]Executing Script on Kudu. Command: %Home%\site\VSTS_PostDeployment_61821533642885586\mainCmdFile.cmd 61821533642885586
2018-08-07T11:54:47.3349805Z ##[debug][POST]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/command
2018-08-07T11:54:50.5826663Z ##[debug]runCommand. Data: {"statusCode":200,"statusMessage":"OK","headers":{"cache-control":"no-cache","pragma":"no-cache","content-length":"162","content-type":"application/json; charset=utf-8","expires":"-1","server":"Apache/2.4.10 (Debian)","x-ms-request-id":"16368886-365f-4237-ba92-944803346ca7","x-aspnet-version":"4.0.30319","set-cookie":["ARRAffinity=63be0527b865f856b484dc6c55de34972eeaf17077dacccb9fa11d7e01640823;Path=/;HttpOnly;Domain=censored-next-linux.scm.azurewebsites.net"],"date":"Tue, 07 Aug 2018 11:54:49 GMT","connection":"close"},"body":{"Output":"","Error":"/opt/Kudu/bin/Scripts/starter.sh: line 2: exec: %Home%siteVSTS_PostDeployment_61821533642885586mainCmdFile.cmd: not found\n","ExitCode":127}}
2018-08-07T11:54:50.5851686Z ##[debug][GET]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/vfs/site/VSTS_PostDeployment_61821533642885586/stdout.txt
2018-08-07T11:54:51.4376480Z ##[debug]getFileContent. Status code: 404 - Not Found
2018-08-07T11:54:51.4381497Z ##[debug][GET]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/vfs/site/VSTS_PostDeployment_61821533642885586/stderr.txt
2018-08-07T11:54:52.8001658Z ##[debug]getFileContent. Status code: 404 - Not Found
2018-08-07T11:54:52.8006570Z ##[debug][GET]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/vfs/site/VSTS_PostDeployment_61821533642885586/script_result.txt
2018-08-07T11:54:53.6757030Z ##[debug]getFileContent. Status code: 404 - Not Found
2018-08-07T11:54:53.6787899Z ##[debug][PUT]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/vfs/site/VSTS_PostDeployment_61821533642885586/delete_log_file.cmd
2018-08-07T11:54:54.4087317Z ##[debug]uploadFile. Data: {"statusCode":200,"statusMessage":"OK","headers":{"server":"Apache/2.4.10 (Debian)","set-cookie":["ARRAffinity=63be0527b865f856b484dc6c55de34972eeaf17077dacccb9fa11d7e01640823;Path=/;HttpOnly;Domain=censored-next-linux.scm.azurewebsites.net"],"date":"Tue, 07 Aug 2018 11:54:53 GMT","connection":"close","content-length":"0"}}
2018-08-07T11:54:54.4090897Z ##[debug]Executing Script on Kudu. Command: delete_log_file.cmd
2018-08-07T11:54:54.4093597Z ##[debug][POST]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/command
2018-08-07T11:54:58.2942772Z ##[debug]runCommand. Data: {"statusCode":200,"statusMessage":"OK","headers":{"cache-control":"no-cache","pragma":"no-cache","content-length":"119","content-type":"application/json; charset=utf-8","expires":"-1","server":"Apache/2.4.10 (Debian)","x-ms-request-id":"272cc42d-a639-402b-979c-9baa9de8f481","x-aspnet-version":"4.0.30319","set-cookie":["ARRAffinity=63be0527b865f856b484dc6c55de34972eeaf17077dacccb9fa11d7e01640823;Path=/;HttpOnly;Domain=censored-next-linux.scm.azurewebsites.net"],"date":"Tue, 07 Aug 2018 11:54:57 GMT","connection":"close"},"body":{"Output":"","Error":"/opt/Kudu/bin/Scripts/starter.sh: line 2: exec: delete_log_file.cmd: not found\n","ExitCode":127}}
2018-08-07T11:54:58.2954945Z ##[debug][DELETE]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/vfs/site/VSTS_PostDeployment_61821533642885586
2018-08-07T11:54:59.5677965Z ##[debug]Encountered a retriable status code: 409. Message: 'Conflict'.
2018-08-07T11:55:01.5748587Z ##[debug][DELETE]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/vfs/site/VSTS_PostDeployment_61821533642885586
2018-08-07T11:55:02.3803802Z ##[debug]Encountered a retriable status code: 409. Message: 'Conflict'.
2018-08-07T11:55:08.3840650Z ##[debug][DELETE]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/vfs/site/VSTS_PostDeployment_61821533642885586
2018-08-07T11:55:09.4217573Z ##[debug]Encountered a retriable status code: 409. Message: 'Conflict'.
2018-08-07T11:55:23.4379600Z ##[debug][DELETE]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/vfs/site/VSTS_PostDeployment_61821533642885586
2018-08-07T11:55:24.1590444Z ##[debug]Encountered a retriable status code: 409. Message: 'Conflict'.
2018-08-07T11:55:54.1753694Z ##[debug][DELETE]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/vfs/site/VSTS_PostDeployment_61821533642885586
2018-08-07T11:55:54.9383871Z ##[debug]deleteFolder. Data: {"statusCode":409,"statusMessage":"Conflict","headers":{"cache-control":"no-cache","pragma":"no-cache","content-length":"87","content-type":"application/json; charset=utf-8","expires":"-1","server":"Apache/2.4.10 (Debian)","x-ms-request-id":"5b8128ee-f848-4174-a073-7d771c08751d","x-aspnet-version":"4.0.30319","set-cookie":["ARRAffinity=63be0527b865f856b484dc6c55de34972eeaf17077dacccb9fa11d7e01640823;Path=/;HttpOnly;Domain=censored-next-linux.scm.azurewebsites.net"],"date":"Tue, 07 Aug 2018 11:55:54 GMT","connection":"close"},"body":{"Message":"Cannot delete directory. It is either not empty or access is not allowed."}}
2018-08-07T11:55:54.9388738Z ##[debug]Unable to delete log files : Error: Failed to delete folder 'site/VSTS_PostDeployment_61821533642885586' from Kudu. Error: Conflict (CODE: 409)
2018-08-07T11:55:54.9390797Z ##[debug]Trying to disable app offline mode.
2018-08-07T11:55:54.9396846Z ##[debug][DELETE]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/vfs/site/wwwroot/app_offline.htm
2018-08-07T11:55:55.5036310Z ##[debug]deleteFile. Data: {"statusCode":200,"statusMessage":"OK","headers":{"cache-control":"no-cache","pragma":"no-cache","content-type":"text/html","expires":"-1","server":"Apache/2.4.10 (Debian)","x-ms-request-id":"77c42bcd-8fe7-4c21-b85f-a14d38569a5e","x-aspnet-version":"4.0.30319","set-cookie":["ARRAffinity=63be0527b865f856b484dc6c55de34972eeaf17077dacccb9fa11d7e01640823;Path=/;HttpOnly;Domain=censored-next-linux.scm.azurewebsites.net"],"date":"Tue, 07 Aug 2018 11:55:54 GMT","connection":"close","content-length":"0"}}
2018-08-07T11:55:55.5038634Z ##[debug]App Offline mode disabled.
2018-08-07T11:55:55.5043713Z ##[debug]Deployment Failed with Error: Error: Unable to run the script on Kudu Service. Error: Error: File not found in Kudu Service. script_result.txt
2018-08-07T11:55:55.5045705Z ##[debug]task result: Failed
2018-08-07T11:55:55.5199298Z ##[error]Error: Unable to run the script on Kudu Service. Error: Error: File not found in Kudu Service. script_result.txt
2018-08-07T11:55:55.5231257Z ##[debug]Processed: ##vso[task.issue type=error;]Error: Unable to run the script on Kudu Service. Error: Error: File not found in Kudu Service. script_result.txt
2018-08-07T11:55:55.5235459Z ##[debug]Processed: ##vso[task.complete result=Failed;]Error: Unable to run the script on Kudu Service. Error: Error: File not found in Kudu Service. script_result.txt
2018-08-07T11:55:55.5237325Z ##[debug][GET]https://management.azure.com/subscriptions/6a1f4abf-xxxx-xxxx-xxxx-c4a7274ee43d/providers/microsoft.insights/components?$filter=InstrumentationKey eq '2cefbd2c-8336-48af-9ce3-fee1e5319daa'&api-version=2015-05-01
2018-08-07T11:55:56.0021832Z ##[debug]Release.ReleaseUri=vstfs:///ReleaseManagement/Release/6182
2018-08-07T11:55:56.0025226Z ##[debug]Build.BuildUri=vstfs:///Build/Build/44418
2018-08-07T11:55:56.0029911Z ##[debug]Release.DefinitionName=xxxxxxx-xxxxxxx-ai-censored-next - CD
2018-08-07T11:55:56.0040559Z ##[debug]Release.ReleaseName=Release-20
2018-08-07T11:55:56.0045163Z ##[debug]Build.BuildUri=vstfs:///Build/Build/44418
2018-08-07T11:55:56.0050086Z ##[debug]Release.ReleaseWebUrl=https://arkadiumarena.visualstudio.com/8d173395-e7e1-4a2b-9797-06e2a6338699/_release?releaseId=6182&_a=release-summary
2018-08-07T11:55:56.0053169Z ##[debug]System.TeamFoundationCollectionUri=https://arkadiumarena.visualstudio.com/
2018-08-07T11:55:56.0056212Z ##[debug]System.TeamProjectId=8d173395-e7e1-4a2b-9797-06e2a6338699
2018-08-07T11:55:56.0058654Z ##[debug]build.buildId=44418
2018-08-07T11:55:56.0116616Z ##[debug][PUT]https://management.azure.com/subscriptions/6a1f4abf-xxxx-xxxx-xxxx-c4a7274ee43d/resourceGroups/censored-next-linux/providers/microsoft.insights/components/censored-next-linux-b985/Annotations?api-version=2015-05-01
2018-08-07T11:55:57.4724719Z ##[debug]addReleaseAnnotation. Data : {"statusCode":200,"statusMessage":"OK","headers":{"cache-control":"no-cache","pragma":"no-cache","content-length":"383","content-type":"application/json; charset=utf-8","expires":"-1","x-ms-request-id":"d8c81dd7-2749-4101-8fcb-122ec5490405","x-content-type-options":"nosniff","strict-transport-security":"max-age=31536000; includeSubDomains","x-ms-ratelimit-remaining-subscription-writes":"1199","server":"Microsoft-IIS/8.5","x-powered-by":"ASP.NET","x-ms-correlation-request-id":"8fbcaeee-063c-4e21-ac32-0ef23f1795a5","x-ms-routing-request-id":"NORTHCENTRALUS:20180807T115557Z:8fbcaeee-063c-4e21-ac32-0ef23f1795a5","date":"Tue, 07 Aug 2018 11:55:57 GMT","connection":"close"},"body":[{"AnnotationName":"xxxxxxx-xxxxxxx-ai-censored-next - CD - Release-20","Id":"e4a5b27a-06c8-405c-a9d3-ae66b5025eb6","Category":"Text","Properties":"{\"Label\":\"Error\",\"Deployment Uri\":\"https://arkadiumarena.visualstudio.com/8d173395-e7e1-4a2b-9797-06e2a6338699/_release?releaseId=6182&_a=release-summary\"}","EventTime":"2018-08-07T11:55:56.004+00:00","RelatedAnnotation":null}]}
2018-08-07T11:55:57.4728599Z Successfully added release annotation to the Application Insight : censored-next-linux-b985
2018-08-07T11:55:57.4737437Z ##[debug]build.sourceVersionAuthor=undefined
2018-08-07T11:55:57.4738481Z ##[debug]build.requestedfor=John Doe
2018-08-07T11:55:57.4739618Z ##[debug]build.buildUri=vstfs:///Build/Build/44418
2018-08-07T11:55:57.4740660Z ##[debug]release.releaseUri=vstfs:///ReleaseManagement/Release/6182
2018-08-07T11:55:57.4741559Z ##[debug]build.buildId=44418
2018-08-07T11:55:57.4742412Z ##[debug]release.releaseId=6182
2018-08-07T11:55:57.4743279Z ##[debug]build.buildNumber=20180806.2
2018-08-07T11:55:57.4744210Z ##[debug]release.releaseName=Release-20
2018-08-07T11:55:57.4745214Z ##[debug]system.TeamFoundationCollectionUri=https://arkadiumarena.visualstudio.com/
2018-08-07T11:55:57.4746210Z ##[debug]system.teamProjectId=8d173395-e7e1-4a2b-9797-06e2a6338699
2018-08-07T11:55:57.4747294Z ##[debug]build.sourceVersion=717626cae293c501130925152fa26590f04c84e4
2018-08-07T11:55:57.4748351Z ##[debug]build.repository.name=xxxxxxx-xxxxxxx-ai-censored
2018-08-07T11:55:57.4749481Z ##[debug]build.repository.provider=TfsGit
2018-08-07T11:55:57.4750460Z ##[debug]build.buildUri=vstfs:///Build/Build/44418
2018-08-07T11:55:57.4751365Z ##[debug]release.releaseUri=vstfs:///ReleaseManagement/Release/6182
2018-08-07T11:55:57.4752564Z ##[debug]build.buildId=44418
2018-08-07T11:55:57.4753508Z ##[debug]release.releaseId=6182
2018-08-07T11:55:57.4754383Z ##[debug]build.buildNumber=20180806.2
2018-08-07T11:55:57.4755267Z ##[debug]release.releaseName=Release-20
2018-08-07T11:55:57.4756274Z ##[debug]system.TeamFoundationCollectionUri=https://arkadiumarena.visualstudio.com/
2018-08-07T11:55:57.4757321Z ##[debug]system.teamProjectId=8d173395-e7e1-4a2b-9797-06e2a6338699
2018-08-07T11:55:57.4758293Z ##[debug]build.sourceVersion=717626cae293c501130925152fa26590f04c84e4
2018-08-07T11:55:57.4759937Z ##[debug]build.repository.name=xxxxxxx-xxxxxxx-ai-censored
2018-08-07T11:55:57.4760908Z ##[debug]build.repository.provider=TfsGit
2018-08-07T11:55:57.4776349Z ##[debug][PUT]https://$censored-next-linux:***@censored-next-linux.scm.azurewebsites.net/api/deployments/61821533642957471
2018-08-07T11:55:58.8541698Z ##[debug]updateDeployment. Data: {"statusCode":200,"statusMessage":"OK","headers":{"cache-control":"no-cache","pragma":"no-cache","content-length":"986","content-type":"application/json; charset=utf-8","expires":"-1","server":"Apache/2.4.10 (Debian)","x-ms-request-id":"3caeb110-3f43-4a8e-80af-ccfcca47b7b7","x-aspnet-version":"4.0.30319","set-cookie":["ARRAffinity=63be0527b865f856b484dc6c55de34972eeaf17077dacccb9fa11d7e01640823;Path=/;HttpOnly;Domain=censored-next-linux.scm.azurewebsites.net"],"date":"Tue, 07 Aug 2018 11:55:58 GMT","connection":"close"},"body":{"id":"61821533642957471","status":3,"status_text":null,"author_email":null,"author":"John Doe","deployer":"VSTS","message":"{\"type\":\"Deployment\",\"commitId\":\"717626cae293c501130925152fa26590f04c84e4\",\"buildId\":\"44418\",\"releaseId\":\"6182\",\"buildNumber\":\"20180806.2\",\"releaseName\":\"Release-20\",\"repoProvider\":\"TfsGit\",\"repoName\":\"xxxxxxx-xxxxxxx-ai-censored\",\"collectionUrl\":\"https://arkadiumarena.visualstudio.com/\",\"teamProject\":\"8d173395-e7e1-4a2b-9797-06e2a6338699\",\"slotName\":\"production\"}","progress":null,"received_time":"0001-01-01T00:00:00","start_time":"2018-08-07T11:55:58.08373Z","end_time":"2018-08-07T11:55:58.08373Z","last_success_end_time":null,"complete":false,"active":false,"is_temp":false,"is_readonly":false,"url":"https://censored-next-linux.scm.azurewebsites.net/api/deployments/61821533642957471","log_url":"https://censored-next-linux.scm.azurewebsites.net/api/deployments/61821533642957471/log","site_name":null}}
2018-08-07T11:55:58.8550848Z Successfully updated deployment History at https://censored-next-linux.scm.azurewebsites.net/api/deployments/61821533642957471
2018-08-07T11:55:58.8552210Z ##[debug]
2018-08-07T11:55:58.8674762Z ##[section]Finishing: Azure App Service Deploy: censored-next-linux

Uploaded gist for convenience

[rand0me]

Btw it deploys successfully, but release showing "Error" status

[vincent1173]

@rand0me .
Currently, we dont have first class support for Linux function apps (exposed in UI). But, Selecting 'Web App on Linux' should work.

[rand0me]

With this setting it takes almost infinity (25 mins and continues).
Could this happen, given that I'm trying to deploy a Function App?

[vincent1173]

@rand0me , sorry for the delayed response.
Can you please leave the release for an hour and observe the behaviour. Debug logs would help in identifying the issue.

[jensholzhause]

We have the same issue on Azure DevOps Server. How can this be fixed?
File: script_result.txt not found. retry after 5 seconds. Attempt: 112