Kudu: Zip deploy failing during unzip to temp folder

[estei]

We have a bunch of node.js micro services and we use the deploy from zip quite heavily.
Most of the time this works like a charm and the deployment unzips and copies all our files to the wwwroot folder as it should.
Sometimes though this breaks down completely, giving us what has now become known on my team as, "The dreaded status 3" :-(
Sometimes retrying helps and the exact same zip file will be properly unzipped and the files copied. At other times this can take 5-6-7-8 retries without working.

Our deployment setup:

Everything runs in Gitlab.
The zip file is built in a ubuntu docker container using the 'zip' command.

We use deployment slots to guarantee that we are always deploying to a new fresh wwwroot filesystem.
Our pipelines in Gitlab automatically removes the old "stage" slot
It then creates a new "stage" slot
We then start the deploy with the /api/zipdeploy?isAsync=true endpoint.
The script then keeps an eye on the deployment until it finishes where we read the value of the status property.
This is where we get a lot of status 3s.

Steps we have tried:

• In an experiment we tried using the Azure Cli (2.0.50 which uses the async API) this shows the same errors.

Logs and observations:

We have tried digging around in the web app to see if we can find some clues as to what is happening.

1. It looks like the zip file fails to unzip into the temp directory. When we look in the D:\local\Temp\zipdeploy the zip file is there and so is an incomplete version of the contents in a folder next to it.
2. It never gets started on the actual deployment, it fails already before it really gets started.

The deployment log:

[
  {
    "log_time": "2018-11-08T14:03:36.5665318Z",
    "id": "f26c83f8-ebe4-4605-82d0-c7d6830ab383",
    "message": "Fetching changes.",
    "type": 0,
    "details_url": "https://sitename-stage.scm.azurewebsites.net/api/deployments/temp-1b69c7fc/log/f26c83f8-ebe4-4605-82d0-c7d6830ab383"
  },
  {
    "log_time": "2018-11-08T14:03:42.7071567Z",
    "id": "0ea63573-dcc9-4510-8f4d-28ac4689240e",
    "message": "An unknown error has occurred. Check the diagnostic log for details.",
    "type": 2,
    "details_url": null
  }
]

Trace log:

LogFiles/kudu/trace/2018-11-08T14-03-35_d282fd_003_Background_POST_api-zipdeploy_pending.xml

<step title="BackgroundTrace" date="2018-11-08T14:03:35.691" instance="d282fd" url="/api/zipdeploy" method="POST" >
<step title="Creating temporary deployment" date="2018-11-08T14:03:36.287" />
<!-- duration: 170ms -->
<step title="Performing fetch based deployment" date="2018-11-08T14:03:36.457" >
<step title="Cleaning up temp folders from previous zip deployments and extracting pushed zip file D:\local\Temp\zipdeploy\xfxzu0p0.zip (5.30 MB) to D:\local\Temp\zipdeploy\extracted" date="2018-11-08T14:03:36.618" >
<step title="Error occurred" date="2018-11-08T14:03:38.754" type="error" text="Thread was being aborted." stackTrace=" at System.Threading.Monitor.ObjWait(Boolean exitContext, Int32 millisecondsTimeout, Object obj)
at System.Threading.Monitor.Wait(Object obj, Int32 millisecondsTimeout, Boolean exitContext)
at System.Threading.Monitor.Wait(Object obj, Int32 millisecondsTimeout)
at System.Threading.ManualResetEventSlim.Wait(Int32 millisecondsTimeout, CancellationToken cancellationToken)
at System.Threading.Tasks.Task.SpinThenBlockingWait(Int32 millisecondsTimeout, CancellationToken cancellationToken)
at System.Threading.Tasks.Task.InternalWait(Int32 millisecondsTimeout, CancellationToken cancellationToken)
at System.Threading.Tasks.Task.Wait(Int32 millisecondsTimeout, CancellationToken cancellationToken)
at Kudu.Core.Deployment.FetchDeploymentManager.&lt;&gt;c__DisplayClass11_1.&lt;PerformBackgroundDeployment&gt;b__3() in C:\Kudu Files\Private\src\master\Kudu.Core\Deployment\FetchDeploymentManager.cs:line 339
at Kudu.Contracts.Infrastructure.LockExtensions.TryLockOperation(IOperationLock lockObj, Action operation, String operationName, TimeSpan timeout) in C:\Kudu Files\Private\src\master\Kudu.Contracts\Infrastructure\LockExtensions.cs:line 34
at Kudu.Contracts.Infrastructure.LockExtensions.LockOperation(IOperationLock lockObj, Action operation, String operationName, TimeSpan timeout) in C:\Kudu Files\Private\src\master\Kudu.Contracts\Infrastructure\LockExtensions.cs:line 46
at Kudu.Core.Deployment.FetchDeploymentManager.&lt;&gt;c__DisplayClass11_0.&lt;PerformBackgroundDeployment&gt;b__1() in C:\Kudu Files\Private\src\master\Kudu.Core\Deployment\FetchDeploymentManager.cs:line 323" />
<!-- duration: 16ms -->
</step>
<!-- duration: 2151ms →

[awentzel]

I filed more details over at https://developercommunity.visualstudio.com/content/problem/435623/zipdeploy-from-azure-devops-task-failing-in-pipeli.html

This error occurs when using App Service Web Deploy (Linux) if you do not create an archive file and deploy that actual archived file, for example, *.zip file using this task. On Windows this does not appear to be a problem. Because Kudu, which is used for ZipDeploy, requires an actual compressed file type, the error messages and all log files show only vague generic warnings and the deployment does still succeed.

Kudu is intelligent enough to upload files to the proper location whether it's a compressed file or no. So, Azure DevOps should be intelligent enough to also report back in logs the valid status instead of throwing an error or partially succeeding. Especially, since in this case there is nothing in the logs on any layer that indicate this problem.

[GFoley83]

This issue has been raised in at least two other places

https://github.com/microsoft/azure-pipelines-tasks/issues/9458
https://developercommunity.visualstudio.com/content/problem/435623/zipdeploy-from-azure-devops-task-failing-in-pipeli.html

Both of which @vincent1173 has closed with a workaround instead of a fix.

Is there any plan to actually fix this?

[ManuInNZ]

Hi there

This is really limiting when trying to use big modules such as tensorflow and so on in Python.

Any option to specify another working directory folder?

Cheers
Manu