azure-pipelinesazure-devops-self-hosted-agent

Why initialize job of Azure DevOps build pipeline takes up so much time?


I have an Azure DevOps project with build pipelines that take too much time to finish. It seems the problem can be pinpointed to the 'Initialize job' and NuGet task. The following steps in 'initialize job' take minutes to finish:

##[debug]Task 'NuGetToolInstaller' already downloaded at 'E:\Agent3\_work\_taskzips\NuGetToolInstaller_2c65196a-54fd-4a02-9be8-d9d1837b7c5d_1.179.0.zip'.
##[debug]Task 'NuGetCommand' already downloaded at 'E:\Agent3\_work\_taskzips\NuGetCommand_333b11bd-d341-40d9-afcf-b32d5ce6f23b_2.179.0.zip'.
##[debug]Task 'PowerShell' already downloaded at 'E:\Agent3\_work\_taskzips\PowerShell_e213ff0f-5d5c-4791-802d-52ea3e7be1f1_1.2.3.zip'.
##[debug]Task 'VSBuild' already downloaded at 'E:\Agent3\_work\_taskzips\VSBuild_71a9a2d3-a98a-4caa-96ab-affca411ecda_1.192.3.zip'.
##[debug]Task 'CopyFiles' already downloaded at 'E:\Agent3\_work\_taskzips\CopyFiles_5bfb729a-a7c8-4a78-a7c3-8d717bb7c13c_2.190.1.zip'.
##[debug]Task 'PublishBuildArtifacts' already downloaded at 'E:\Agent3\_work\_taskzips\PublishBuildArtifacts_2ff763a7-ce83-4e1f-bc89-0ae63477cebe_1.192.0.zip'.

Also the following step in task NuGet takes a lot of time:

##[debug]Extracting task NuGetCommand from E:\Agent3\_work\_taskzips\NuGetCommand_333b11bd-d341-40d9-afcf-b32d5ce6f23b_2.179.0.zip to E:\Agent3\_work\_tasks\NuGetCommand_333b11bd-d341-40d9-afcf-b32d5ce6f23b\2.179.0.

The strange this is that pipelines in a different project and organization with seemingly the same build definitions and agent version are not slow (seconds) and give different debug output:

##[debug]Task 'NuGetToolInstaller' already downloaded at 'E:\agent\_work\_tasks\NuGetToolInstaller_2c65196a-54fd-4a02-9be8-d9d1837b7c5d\1.179.0'.
##[debug]Task 'NuGetCommand' already downloaded at 'E:\agent\_work\_tasks\NuGetCommand_333b11bd-d341-40d9-afcf-b32d5ce6f23b\2.179.0'.
##[debug]Task 'PowerShell' already downloaded at 'E:\agent\_work\_tasks\PowerShell_e213ff0f-5d5c-4791-802d-52ea3e7be1f1\1.2.3'.
##[debug]Task 'VSBuild' already downloaded at 'E:\agent\_work\_tasks\VSBuild_71a9a2d3-a98a-4caa-96ab-affca411ecda\1.192.3'.
##[debug]Task 'CopyFiles' already downloaded at 'E:\agent\_work\_tasks\CopyFiles_5bfb729a-a7c8-4a78-a7c3-8d717bb7c13c\2.190.1'.
##[debug]Task 'PublishBuildArtifacts' already downloaded at 'E:\agent\_work\_tasks\PublishBuildArtifacts_2ff763a7-ce83-4e1f-bc89-0ae63477cebe\1.192.0'.

It looks like the slow agent is using taskzips folder and the fast agent is using the tasks folder. The self hosted agents both run on the same on-premise server. I looked in the folders and the takszips folder contains zip files:

       Directory: \\atsmodapp01\e$\Agent3\_work\_taskzips

Mode                 LastWriteTime         Length Name
----                 -------------         ------ ----
-a---          07/10/2021    12:52         573233 CopyFiles_5bfb729a-a7c8-4a78-a7c3-8d717bb7c13c_2.190.1.zip
-a---          07/10/2021    12:52       25890948 NuGetCommand_333b11bd-d341-40d9-afcf-b32d5ce6f23b_2.179.0.zip
-a---          07/10/2021    12:51        4613826 NuGetToolInstaller_2c65196a-54fd-4a02-9be8-d9d1837b7c5d_1.179.0.zip
-a---          07/10/2021    12:52          13477 PowerShell_e213ff0f-5d5c-4791-802d-52ea3e7be1f1_1.2.3.zip
-a---          07/10/2021    12:52         974971 PublishBuildArtifacts_2ff763a7-ce83-4e1f-bc89-0ae63477cebe_1.192.0.zip
-a---          07/10/2021    12:52         588839 VSBuild_71a9a2d3-a98a-4caa-96ab-affca411ecda_1.192.3.zip

The tasks folder contains folders:

    Directory: \\atsmodapp01\e$\agent\_work\_tasks

Mode                 LastWriteTime         Length Name
----                 -------------         ------ ----
d----          22/10/2020    13:50                Bash_6c731c3c-3c68-459a-a5c9-bde6e6595b5b
d----          17/02/2021    11:44                CmdLine_d9bafed4-0b18-4f58-968d-86655b4d2ce9
d----          02/08/2021    12:41                CopyFiles_5bfb729a-a7c8-4a78-a7c3-8d717bb7c13c
d----          03/03/2021    06:40                DeleteFiles_b7e8b412-0437-4065-9371-edc5881de25b
d----          03/09/2021    12:36                DownloadBuildArtifacts_a433f589-fce1-4460-9ee6-44a624aeb1fb
d----          22/07/2019    15:35                DownloadFileshareArtifacts_e3cf3806-ad30-4ec4-8f1e-8ecd98771aa0
d----          22/07/2019    15:34                DownloadPackage_8d6e8f7e-267d-442d-8c92-1f586864c62f
d----          30/10/2019    15:28                GenerateReleaseNotes_661bc005-61be-430f-b994-065bf08c0f39
d----          30/03/2021    09:36                gitsync_36cbb8f8-6f18-4b55-bdd7-3ecf87044b08
d----          22/11/2020    17:45                GitTag_be6aa0ca-e62f-414d-aaa6-e9524b556482
d----          15/12/2020    12:18                NuGetCommand_333b11bd-d341-40d9-afcf-b32d5ce6f23b
d----          22/07/2019    15:31                NuGetRestore_333b11bd-d341-40d9-afcf-b32d5ce6f23b
d----          15/12/2020    12:18                NuGetToolInstaller_2c65196a-54fd-4a02-9be8-d9d1837b7c5d
d----          30/06/2020    21:16                PowerShell_e213ff0f-5d5c-4791-802d-52ea3e7be1f1
d----          15/09/2021    14:52                PublishBuildArtifacts_2ff763a7-ce83-4e1f-bc89-0ae63477cebe
d----          04/11/2020    12:05                RedgateSqlChangeAutomationBuild_7345fe1b-d099-46f0-a0d1-7292cd17feee
d----          04/11/2020    16:54                RedgateSqlChangeAutomationRelease_c1177c17-3934-4005-ba89-a4549fe4f0a1
d----          26/10/2020    09:40                replacetokens_a8515ec8-7254-4ffd-912c-86772e2b5962
d----          27/09/2020    21:45                rvo-vsts-promotepackage-task_7ca5869f-a901-4012-a50d-d0f9d436ffec
d----          21/07/2021    18:43                UniversalPackages_e0b79640-8625-11e8-91be-db2878ff888a
d----          21/09/2021    16:02                VSBuild_71a9a2d3-a98a-4caa-96ab-affca411ecda
d----          26/10/2020    09:40                xdttransform_98012758-c053-475d-9d6a-fd0773c39e09

My questions are: why do the agents, processing the pipelines, behave differently and how can I make the slow agent faster or change it so the that it behaves like the fast agent?

Regards,

Patrick


Solution

  • The difference must be in the .agent config file which is located in the root of the agent installation folder.

    In your case: E:\Agent3\

    In this JSON style config file a entry named "alwaysExtractTask" is be present. Please remove the alwaysExtractTask line or alter it to False.

    https://i.imgur.com/93ypRGc.png

    Now restart the service and see that your agent is fast as f boi!

    Background info:

    Please check these release note for more explanation on alwaysExtractTask.

    UPDATE: This configuration was a short time part of the installation questions, but Microsoft removed it since June this year.