Azure-pipelines-tasks: DeleteFiles Task Taking Much Longer Than It Used To

[cvillhauer]

Required Information

Entering this information will route you directly to the right team and expedite traction.

Question, Bug, or Feature?
Type: Question

Enter Task Name: DeleteFilesV1

Specifically 1.165.0 vs 1.154.0

Environment

• Server - Azure Pipelines or TFS on-premises?

  • Azure Pipelines

• Agent - Hosted or Private:

  • Private: Agent versions 2.153.2 and 2.163.1, on Windows Server 2012 R2 and Windows Server 2016 respectively

Issue Description

What changed between version 1.154.0 and 1.165.0 of the DeleteFilesV1 task?

We have several build pipelines that finish up with a Delete Files from $(Build.SourcesDirectory) step. Those delete steps are now consistently taking more than 10 times longer to run in version 1.165.0 than they did with version 1.154.0.

Here are some examples:

• Build A, on Agent version 2.153.2, Windows Server 2012 R2
  Ran on Feb 24 with version 1.154.0: DeleteFiles step took 4 seconds
  Ran on Feb 25 with version 1.154.0: DeleteFiles step took 4 seconds
  Ran on Mar 5 with version 1.165.0: DeleteFiles step took 102 seconds
  Ran on Mar 9 with version 1.165.0: DeleteFiles step took 97 seconds

• Build B, on Agent version 2.153.2, Windows Server 2012 R2
  Ran on Feb 17 with version 1.154.0: DeleteFiles step took 6 seconds
  Ran on Feb 25 with version 1.154.0: DeleteFiles step took 8 seconds
  Ran on Feb 27 with version 1.165.0: DeleteFiles step took 200 seconds
  Ran on Mar 9 with version 1.165.0: DeleteFiles step took 196 seconds

• Build C, on Agent version 2.163.1, Windows Server 2016
  Ran on Feb 24 with version 1.154.0: DeleteFiles step took 1 second
  Ran on Feb 25 with version 1.154.0: DeleteFiles step took 1 second
  Ran on Feb 26 with version 1.165.0: DeleteFiles step took 14 seconds
  Ran on Mar 2 with version 1.165.0: DeleteFiles step took 16 seconds

• Build D, on Agent version 2.163.1, Windows Server 2016
  Ran on Feb 24 with version 1.154.0: DeleteFiles step took 78 seconds
  Ran on Feb 25 with version 1.154.0: DeleteFiles step took 77 seconds
  Ran on Feb 26 with version 1.165.0: DeleteFiles step took 1107 seconds
  Ran on Mar 2 with version 1.165.0: DeleteFiles step took 1073 seconds

[damccorm]

Hey @cvillhauer - as far as I know there weren't any changes on our end that should've caused this. Could you try running a build with system diagnostics turned on and either share the logs or, if you're not comfortable with that, look at timestamps and share what part of the task is taking longer

[waldemarsvk]

Hi, i'm experiencing the same issue with the Deletion taks taking much longer in version 1.165.0 (from about 10 seconds it now takes around 8-10 minutes). Will try to run it with system diagnostic on and let you know what is there.

Edit 15:47:
So the deletion of the files seems slow. It takes aroun 1 second to delete cca 15 files.
Every file is deleted with it's own "rm -rf path" command (i don't know if it's ok this way..i saw the logs for the first time)
The deletion seems to be sorted - it deletes files from the longest path to the shortest. This seems to be weird.

[cvillhauer]

@damccorm - I am seeing the same thing that @waldemarsvk is seeing. It's deleting about 38 files per second for me.

I ran this with system diagnostics on for Build A. First it spends about 2 seconds identifying the 3674 files to delete, and then for each file it lists these steps in the log:
2020-03-19T18:45:35.9995301Z ##[debug]rm -rf C:\Agent_work\278\s[redactedl
2020-03-19T18:45:35.9997220Z ##[debug]removing file C:\Agent_work\278\s[redacted]

In total the delete step took 96 seconds.

[rdrrichards]

Similar experience here. The delete files task that used to take about 1.5 minutes with an application that includes a node_modules folder (an Angular 9.0.0 application), sometimes takes 28 minutes now.

The diagnostic log doesn't show anything different than what has been reported above. Roughly 40 files per second are deleted. A node_modules folder can easily contain over 10,000 files.

[acbush]

This issue is causing some significant disruption to our development team flow as it is introducing significant delays into our process. We really need a solution or a workaround. Can the label on this issue be changed from "question" to "bug"?

[keenanmj]

Bumping this for visibility, we started experiencing this issue on May 19th, 2020. Time to delete went from <1 minute to 8+ minutes consistently.

[damccorm]

Hi all, sorry this has sat for a while. I think this is a somewhat unfortunate but unavoidable consequence of updating the task-lib to consume this pr - https://github.com/microsoft/azure-pipelines-task-lib/pull/531. Basically, the short version is that before this change, we were using node's built in unlinkSync function to delete things, now we're shelling out to the file system to do the work for us.

We needed to do this because Node doesn't actually delete files with unlinkSync, it just decrements their ref counts. Naturally that's a lighter-weight/faster process, but it may not actually delete files (e.g. if the file is open elsewhere or an antivirus is holding it open). See https://github.com/Microsoft/azure-pipelines-tasks/issues/5472 for more info (I jumped the gun on that issue and declared it fixed a little before it had rolled out fully, so some conversation at the end is a little off topic).

[cvillhauer]

Thanks @damccorm - The item you linked is definitely related, and the timing matches up.

We were actually using the Delete task to clean up our build server, wiping out $(Build.SourcesDirectory) and $(Build.ArtifactStagingDirectory). In the past, we've had issues with the Checkout/Get Sources steps throwing errors if these Delete tasks hadn't been done on the previous build.

Now that these delete workarounds are not needed, the issue of the Delete task taking a long time is solved by removing the Delete step from our builds.

[rpeltola]

Should this be reopened since it's actual problem if trying to use the task? @damccorm

Older version of DeleteFilesV1 took about 6 seconds for us (6679 files, 1134 folders, 446MB in size), now it takes little under 3min for the same files.

Yes, we could use Powershell script, but what is the use of Delete files task if it's so slow that it's almost unusable?