Pages

Friday, July 26, 2019

Azure DevOps Build Queue Wait Time

Azure DevOps is used to automate CI/CD pipelines. It uses an agent to execute one job at a time. If we have more jobs to execute than agents then some jobs have to wait in the queue. This post is about how to gather metrics about the wait time to decide when to add more agents.

Agents are organized into pools and the data needed is available via REST API.  The URI to list the pools is

https://dev.azure.com/{your organization}/_apis/distributedtask/pools

and the URI to list the jobs running on each pool is

https://dev.azure.com/{your organization}/_apis/distributedtask/pools/{pool id}/jobrequest

To authenticate to Azure DevOps, you will need your access token and replace it in the PowerShell script below

$token = "{your access token}"
$bytes = [System.Text.Encoding]::UTF8.GetBytes(":$($token)")
$base64bytes = [System.Convert]::ToBase64String($bytes)
$headers = @{ "Authorization" = "Basic $base64bytes"}

$uri = 'https://dev.azure.com/{your organization}/_apis/distributedtask/pools/{pool id}/jobrequests'

$r = Invoke-RestMethod -Uri $uri -Headers $headers -Method Get -ContentType "application/json"


The result is a PSCustomObject with other nested PSCustomObject as Get-Member shows, so  expressions are needed to query the nested objects for example reservedAgent. The time fields such as queueTime are strings, so expressions are also required to convert to universal time

$r.value | gm

   TypeName: System.Management.Automation.PSCustomObject

Name                   MemberType   Definition
----                   ----------   ----------
Equals                 Method       bool Equals(System.Object obj)                     
GetHashCode            Method       int GetHashCode()                                  
GetType                Method       type GetType()                                     
ToString               Method       string ToString()                                  
agentDelays            NoteProperty Object[] agentDelays=System.Object[]               
assignTime             NoteProperty string assignTime=2019-07-19T21:40:26.8666667Z     
data                   NoteProperty System.Management.Automation.PSCustomObject
definition             NoteProperty System.Management.Automation.PSCustomObject
demands                NoteProperty Object[] demands=System.Object[]                   
hostId                 NoteProperty string hostId=22399273-0444-4322-aea9-2e628bac6c60 
jobId                  NoteProperty string jobId=12f1170f-54f2-53f3-20dd-22fc7dff55f9  
lockedUntil            NoteProperty string lockedUntil=2019-07-19T22:05:33.4833333Z    
matchesAllAgentsInPool NoteProperty bool matchesAllAgentsInPool=True                   
orchestrationId        NoteProperty string orchestrationId=d476f3d0-c2b4-41d5-9ebb
owner                  NoteProperty System.Management.Automation.PSCustomObject
planId                 NoteProperty string planId=d476f3d0-c2b4-41d5-9ebb-789eb9704ca7 
planType               NoteProperty string planType=Build                              
poolId                 NoteProperty int poolId=9                                       
queueTime              NoteProperty string queueTime=2019-07-19T21:40:26.4633333Z      
receiveTime            NoteProperty string receiveTime=2019-07-19T21:40:29.379468Z     
requestId              NoteProperty int requestId=1024                                 
reservedAgent          NoteProperty System.Management.Automation.PSCustomObject 
scopeId                NoteProperty string scopeId=0020fc51-3569-4cdc-8c2b-2affa5401996
serviceOwner           NoteProperty string serviceOwner=00025394-6065-48ca-87d


The final script parses the required info and filters out Pool Maintenance jobs and data older than 3 hours using Where-Object.

$r.value `
| Select-Object requestId, poolId, result,`
  @{Label=”name”; Expression={$_.definition.name}},`
  @{Label=”agent”; Expression={$_.reservedAgent.name}},`
  @{Label=”queued”; Expression={(get-date $_.queueTime).ToUniversalTime()}},` 
  @{Label=”assigned”; Expression={(get-date $_.assignTime).ToUniversalTime()}},` 
  @{Label=”received”; Expression={(get-date $_.receiveTime).ToUniversalTime()}},` 
  @{Label=”finished”; Expression={(get-date $_.finishTime).ToUniversalTime()}}`
| Where-Object {$_.name -ne 'PoolMaintenance' `
  -and $_.queued -gt (Get-Date).AddHours(-3).ToUniversalTime()}`
| Select-Object requestId, poolId, result, name, agent, queued,`
  @{Label=”wait”; Expression={$_.assigned-$_.queued}},`
  @{Label=”duration”; Expression={$_.finished-$_.received}}`
| Format-Table

requestId poolId result    name              agent   queued                wait     duration
--------- ------ ------    ----              -----   ------                ----     --------
     1023      9 succeeded project-for-demo2 AGENT01 7/19/2019 8:00:31 PM  00:33:40 00:00:25
     1022      9 succeeded project-for-demo1 AGENT01 7/19/2019 7:55:04 PM  00:00:00 00:38:03


From the results above, request id 1023 was waiting 33 minutes for request id 1022 to complete. If a 33 minute wait is not acceptable then a second agent can be added to process the job. Also this data can be collected and stored for trend analysis.