Zip deploy (/api/zipdeploy?isAsync=true) is taking too long and not coming back with any response for 20+ minutes

[Zhanelya]

Hi,

Repro steps.

The project builds OK on Azure Devops, but when it gets to deployment it sporadically failes on timeout as zipdeploy task is taking too long.

We use a powershell script made up of 2 parts for deployment.

One part is sending a request to zipdeploy with a zip file to deploy to Azure slot, and another part is then pinging the api after to check if deployment has completed.

For some reason this first part just hangs for a very long time. The zip size is about 170MB, so it can't be that it is uploading the zip file for 20 minutes or more can it?

Here is the part of the powershell script that we use for the first part I mentioned above:

$request = Invoke-WebRequest -Uri "$ScmSiteUri/api/zipdeploy?isAsync=true" -Headers @{Authorization=("Basic {0}" -f $appServiceScmLoginToken)} -UserAgent "powershell/5.0" -Method POST -TimeoutSec 1200 -ContentType "multipart/form-data" -InFile $ZipFilePath ` -UseBasicParsing ;

We are using it inside a Powershell task of the following version:

Task : Azure PowerShell Description : Run a PowerShell script within an Azure environment Version : 5.173.1 Author : Microsoft Corporation Help : https://aka.ms/azurepowershelltroubleshooting

Can someone please help to figure out why an async file zipdeploy call (which shouldn't really do anything else other than upload a zip and request deployment) is taking so long?

Project structures.

The project is just a standard php web app built on Zend, there is quite a number of files, but other than that, there is nothing special about it

The log/error given by the failure.

The request is just taking a very long time. Even though in your documentation it says that "You will receive a response as soon as the zip file is uploaded with a Location header pointing to the pollable deployment status URL.". (https://github.com/projectkudu/kudu/wiki/Deploying-from-a-zip-file-or-url)

Debug your Azure website remotely.

Our subscription is a6d47e....1af9b7e4, and the website that we're trying to deploy is ...-webapp-dev1 (I've omitted some parts of the full names as this is a public post), but feel free to request any other details if necessary for debugging.

Will be looking forward to hearing from you.

Thank you, Zhanelya

[suwatch]

Thank for the thorough description - always help speed things up. We look at the most recent deployments below. They all seemed fine and taking < 18s. Please provide the UTC time of the issue so we can pinpoint.

UTC	Status	MilliSeconds
2020-09-03 22:29:59.2590000	202	11765
2020-09-04 05:51:38.4450000	202	18735
2020-09-04 07:58:00.0860000	202	9250
2020-09-04 08:16:59.8320000	202	9610

[Zhanelya]

Hi,

Thank you for getting back to us and taking a proper look at the issue.

I'm not sure if these numbers are correct. Here's the log from the first deployment you mentioned - it didn't take 11765 miliseconds but took about 18 minutes to get the response back from zipdeploy. Unless there's an issue with invoking the request.

A call to zipdeploy and pinging the deployment status afterwards together took 24 minutes to complete. The pinging part was going on for about 5 minutes, and the rest of the time our powershell system was waiting for the response from zipdeploy URL.

2020-09-03T22:11:54.4309271Z Obtaining App Service Publish Credential for App Service ...webapp-dev1 and slot name staging 2020-09-03T22:11:54.4309704Z 2020-09-03T22:11:55.1595366Z Success 2020-09-03T22:11:55.1603638Z 2020-09-03T22:11:55.1621490Z Starting KUDU ZIP deployment asynchrounously 2020-09-03T22:11:55.1627428Z 2020-09-03T22:29:59.3644579Z Deployment started, progress can be checked at https://...webapp-dev1-staging.scm.azurewebsites.net/api/deployments/latest?deployer=ZipDeploy&time=2020-09-03_22-29-59Z 2020-09-03T22:29:59.3648340Z

Here's part of powershell script that generated the above logs for this deployment

    Write-Host "Starting KUDU ZIP deployment asynchrounously"
    Write-Host 

    $request = Invoke-WebRequest -Uri "$ScmSiteUri/api/zipdeploy?isAsync=true" `
        -Headers @{Authorization=("Basic {0}" -f $appServiceScmLoginToken)} `
        -UserAgent "powershell/5.0" `
        -Method POST `
        -TimeoutSec 2400 `
        -ContentType "multipart/form-data" `
        -InFile $ZipFilePath `
        -UseBasicParsing
        ;

    Write-Host "Deployment started, progress can be checked at $($request.Headers.Location)";
    Write-Host

[Zhanelya]

Here's another piece of logs from a different deployment that is from yesterday in case you find it useful:

2020-09-07T12:45:31.8029320Z Starting KUDU ZIP deployment asynchrounously 2020-09-07T12:45:31.8049097Z 2020-09-07T13:06:00.6659855Z Deployment started, progress can be checked at https://...webapp-dev1-staging.scm.azurewebsites.net/api/deployments/latest?deployer=ZipDeploy&time=2020-09-07_13-06-00Z 2020-09-07T13:06:00.6667633Z 2020-09-07T13:06:00.7128757Z Parameters:

[Zhanelya]

And here's another one for today

2020-09-08T11:29:58.3613808Z 2020-09-08T11:29:59.3370040Z Success 2020-09-08T11:29:59.3380403Z 2020-09-08T11:29:59.3394857Z Starting KUDU ZIP deployment asynchrounously 2020-09-08T11:29:59.3400730Z 2020-09-08T11:47:13.3445657Z Deployment started, progress can be checked at https://...webapp-dev1-staging.scm.azurewebsites.net/api/deployments/latest?deployer=ZipDeploy&time=2020-09-08_11-47-12Z 2020-09-08T11:47:13.3514715Z

[Zhanelya]

Hi @suwatch ,

Do you need any further information from us to help you with our issue?

Thank you, Zhanelya

[suwatch]

I think the time taken is to upload your zip file from local machine to SCM which was not capture on our log. Instead of uploading from local machine, try pre-upload somewhere and use this. See if that makes any different.

[Zhanelya]

Hi @suwatch ,

Thank you for getting back to us.

The zip file isn't really uploaded from a local machine - the app is being built our Azure DevOps server, and the result is then uploaded from there to Azure slot. I am not sure where else we can pre-upload it to, and if it would help anything? Also, I believe we already are using zipdeploy API you shared a link for? Something that we noticed also is that it is very sporadic and sometimes it takes 20+ minutes for that upload task, and sometimes it takes just 5-7 minutes to complete.

Here are the 2 pieces of code that deal with the build and deployment onto the slot using zipdeploy:

Main build/deployment flow:

...
- task: PowerShell@2
      displayName: Create-Zip-Archive
      inputs:
        filePath: '$(System.DefaultWorkingDirectory)\Deployment\Tasks\Create-Zip-Archive.ps1'
        arguments: '-SourcePath "$(System.DefaultWorkingDirectory)\ABACUS-WebApp" -DestinationPath "$(System.DefaultWorkingDirectory)\Deployment\ABACUS-WebApp.zip"'

    - publish: $(System.DefaultWorkingDirectory)\Deployment
      artifact: Deployment

// ... run some tests before deployment

- task: AzurePowerShell@5
      displayName: Set-App-Service-Zip-Deployment-Async
      inputs:
        azureSubscription: 'VSTS - Infrastructure'
        ScriptType: 'FilePath'
        ScriptPath: '$(Pipeline.Workspace)\Deployment\Tasks\Set-App-Service-Zip-Deployment-Async.ps1'
        ScriptArguments: '-ResourceGroupName "...-webapp-dev1" -AppServiceName "...-webapp-dev1" -AppServiceSlotName "staging" -ScmSiteUri "https://...-webapp-dev1-staging.scm.azurewebsites.net" -ZipFilePath "$(Pipeline.Workspace)\Deployment\ABACUS-WebApp.zip"'
        azurePowerShellVersion: 'LatestVersion'

....

Create-Zip-Archive.ps1:

<############################################################################
        Params
#############################################################################>

[CmdletBinding()]
Param(
   [Parameter(Mandatory=$True,Position=1)]
   [string] $SourcePath,

   [Parameter(Mandatory=$True,Position=2)]
   [string] $DestinationPath

)

<############################################################################
        Script Config
#############################################################################>

Set-ExecutionPolicy -Scope Process -ExecutionPolicy Bypass

$scriptPath = split-path -parent $MyInvocation.MyCommand.Definition
Set-Location $scriptPath

<############################################################################
        Functions
#############################################################################>

Function CreateWebZipArchive(
    [string] $SourcePath,
    [string] $DestinationPath

) {

    Write-Host "Parameters:";
    Write-Host "Source Path: $($SourcePath)";
    Write-Host "Destination Path: $($DestinationPath)";
    Write-Host "Exclude File or Folders: $($ExcludeFileOrFolders)";
    Write-Host

    $SourceSrc = $SourcePath;
    $DestSrc = $DestinationPath;

    Write-Host "Creating ZIP Archive from $($SourceSrc) to $($DestSrc) ";
    Write-Host

    try {

        # Delete Existing

        if($true -eq (Test-Path -Path $DestSrc)) {
            Remove-Item $DestSrc -Force -ErrorAction SilentlyContinue
        }

        $Files = Get-ChildItem -Path $SourceSrc;

        # Create Archive

        $Files | Compress-Archive -DestinationPath $destSrc -Update -CompressionLevel Optimal

        Write-Host "Success" -ForegroundColor Green;
        Write-Host

        break

    } catch {
        Write-Host $_.Exception.Message -ForegroundColor Yellow;
        Write-Host "Failed" -ForegroundColor Red
        Write-Host
        throw $_.Exception
    }
}

<############################################################################
        Execution
#############################################################################>

CreateWebZipArchive $SourcePath $DestinationPath;

Set-App-Service-Zip-Deployment-Async.ps1

<############################################################################
        Params
#############################################################################>

[CmdletBinding()]
Param(
   [Parameter(Mandatory=$True,Position=1)]
   [string] $ResourceGroupName,

   [Parameter(Mandatory=$True,Position=2)]
   [string] $AppServiceName,

   [Parameter(Mandatory=$True,Position=3)]
   [string] $AppServiceSlotName,

   [Parameter(Mandatory=$True,Position=4)]
   [string] $ScmSiteUri,

   [Parameter(Mandatory=$True,Position=5)]
   [string] $ZipFilePath
)

<############################################################################
        Script Config
#############################################################################>

Set-ExecutionPolicy -Scope Process -ExecutionPolicy Bypass

$scriptPath = split-path -parent $MyInvocation.MyCommand.Definition
Set-Location $scriptPath

. ".\Includes\Azure-Login.ps1"
. ".\Includes\Get-App-Service-Scm-Login-Token.ps1"
. ".\Includes\Get-Azure-Ad-Token.ps1"

<############################################################################
        Functions
#############################################################################>

Function SetAppServiceZipDeploymentAsync(
    [string] $ResourceGroupName,
    [string] $AppServiceName,
    [string] $AppServiceSlotName,
    [string] $ScmSiteUri,
    [string] $ZipFilePath

) {

    Write-Host "Parameters:";
    Write-Host "Resource Group Name: $($ResourceGroupName)";
    Write-Host "App Service Name: $($AppServiceName)";
    Write-Host "App Service Slot Name: $($AppServiceSlotName)";
    Write-Host "Scm Site Uri: $($ScmSiteUri)";
    Write-Host "ZipFilePath: $($ZipFilePath)";
    Write-Host

    try {

        # Login to Azure

        AzureLogin;

        $appServiceScmLoginToken = GetAppServiceScmLoginToken -ResourceGroupName $ResourceGroupName -AppServiceName $AppServiceName -AppServiceSlotName $AppServiceSlotName;

        Write-Host "Starting KUDU ZIP deployment asynchrounously"
        Write-Host 

        $request = Invoke-WebRequest -Uri "$ScmSiteUri/api/zipdeploy?isAsync=true" `
            -Headers @{Authorization=("Basic {0}" -f $appServiceScmLoginToken)} `
            -UserAgent "powershell/5.0" `
            -Method POST `
            -TimeoutSec 2400 `
            -ContentType "multipart/form-data" `
            -InFile $ZipFilePath `
            -UseBasicParsing
            ;

        Write-Host "Deployment started, progress can be checked at $($request.Headers.Location)";
        Write-Host

        $i = 0;

        while((GetAppServiceZipDeploymentAsync -ResourceGroupName $ResourceGroupName -AppServiceName $AppServiceName -AppServiceSlotName $AppServiceSlotName -ScmSiteUri $request.Headers.Location) -eq $false) {
            if($i -eq 30) {
                throw "This deployment has exceeded 30 minutes. It has probably timed out. Bailing...";
            }
            Write-Host "Deploying zip file for $($i) minutes";
            $i = $i+1;
            Start-Sleep -Seconds 60;
        }

        Write-Host "Success" -ForegroundColor Green
        Write-Host

    } catch {
        Write-Host "Failed" -ForegroundColor Red
        Write-Host $_.Exception.Message;
        Write-Host
        throw $_.Exception
        Exit 1
    }
}

Function GetAppServiceZipDeploymentAsync(
    [string] $ResourceGroupName,
    [string] $AppServiceName,
    [string] $AppServiceSlotName,
    [string] $ScmSiteUri
) {

    try {

        # Login to Azure

        AzureLogin;

        $appServiceScmLoginToken = GetAppServiceScmLoginToken -ResourceGroupName $ResourceGroupName -AppServiceName $AppServiceName -AppServiceSlotName $AppServiceSlotName;

        Write-Host "Retrieving deployment status from $($ScmSiteUri)";

        $request = Invoke-RestMethod -Uri "$($ScmSiteUri)" `
            -Headers @{Authorization=("Basic {0}" -f $appServiceScmLoginToken)} `
            -UserAgent "powershell/5.0" `
            -Method GET `
            -TimeoutSec 60 `
            -ContentType "application/json" `
            ;

        Write-Host "complete: $($request.complete)";
        Write-Host "status: $($request.status)";
        Write-Host "status_text: $($request.text)";
        Write-Host "progress: $($request.progress)";
        Write-Host "log_url: $($request.log_url)";
        Write-Host

        if($request.complete -eq $false) {
            Return $False;
        } else {
            if($request.status -eq "4") {
                return $True;
            } else {
                throw "The deployment has failed. Further info available at $($ScmSiteUri).";
            }
        }

    } catch {
        Write-Host "Failed" -ForegroundColor Red
        Write-Host $_.Exception.Message;
        Write-Host
        throw $_.Exception
        Exit 1
    }
}

<############################################################################
        Execution
#############################################################################>

SetAppServiceZipDeploymentAsync -ResourceGroupName $ResourceGroupName `
-AppServiceName $AppServiceName `
-AppServiceSlotName $AppServiceSlotName `
-ScmSiteUri $ScmSiteUri `
-ZipFilePath $ZipFilePath;

Let me know what you think.

Thank you, Zhanelya

[Zhanelya]

Now thinking of your response again, I may have misunderstood it. We have a build agent, which is probably where the zip upload is actually happening. But then this is the advised way I believe to have a VM allocated to a build agent on Azure Devops. So, I'm not sure where else are you advising to uploaded this zip and wouldn't it add even more latency time if we upload it to another place first?

Thank you

[Zhanelya]

Hi,

It's been a while and I thought it may be worth to follow up. We noticed that zipping the artifact takes a real while too, and it is very inconsistent in terms of how long it takes. So, preparing and zipping the artifact and doing zipdeploy after are the parts that take the longest. Do you have any suggestions on how we can solve this? The builds are running on a VM.

Thank you

[Zhanelya]

We tried to download the zipped artifact and unzip it on just a normal laptop and it takes only 2-3m to do that, which is why we don't understand why it takes so long on the VM when run with Azure Devops.

Would appreciate your thoughts!

Thank you

[Zhanelya]

Hi, any update on this please?

[RScanlan1990]

If anyone else has this issue, we have swapped $request = Invoke-RestMethod...... with

        $Request = [System.Net.HttpWebRequest]::CreateHttp("$ScmSiteUri/api/zipdeploy?isAsync=true");

The upload now takes a few seconds from Azure microsoft hosted agent. Seems Invoke-WebRequest is just slow. Bing Search 'Invoke-WebRequest Slow'

[jvano]

Hi

If the problem persists and is related to running it on Azure App Service, please open a support incident in Azure: https://learn.microsoft.com/en-us/azure/azure-portal/supportability/how-to-create-azure-support-request

This way we can better track and assist you on this case

Thanks,

Joaquin Vano Azure App Service