Home: NuGet.exe pack performance problem with `..` relative path

[jussimattila]

Description

I'm NuGet packing our JavaScript application for Octopus Deploy to deploy to a test server. All content in the unbundled app creates a 40 MB NuGet package including ~8000 files. This was never a problem, as with 3.5.0 packing the app was quite quick. After upgrading to Visual Studio 2017 and NuGet 4.1.0, our build server started failing on the packaging step since it timeouts after 5 minutes. While trying to reproduce this, I found out that the timeout occurs only when using a .. relative path for including files.

Example

Packing the same .nuspec file from the command line produces these results:

NuGet.exe 3.5.0 vs NuGet.exe 4.1.0

PS {~\D\e\n\script> .\repro.ps1

Wednesday 12. April 2017 12.44.58
Attempting to build package from 'nuget-performance-test.nuspec'.
Successfully created package
'C:\Users\Jussi\Documents\edit-temp\nuget_perf_repro\script\NuGet.Performance.Test.3.5.0.nupkg'.
Wednesay 12. April  2017 12.45.00
Attempting to build package from 'nuget-performance-test.nuspec'.
Successfully created package
'C:\Users\Jussi\Documents\edit-temp\nuget_perf_repro\script\NuGet.Performance.Test.4.1.0.nupkg'.
Wednesay 12. April  2017 12.45.34

Example results

With 3.5.0, packing the app took ~2 seconds.
With 4.1.0, packing the app took ~34 seconds.

On an actual project

With our actual application, the difference looks like this on the build server:
With 3.5.0, packing the app took ~20 seconds.
With 4.1.0, packing the app took ~9 minutes.

Details about Problem

NuGet product used (NuGet.exe | VS UI | Package Manager Console | dotnet.exe):
NuGet.Exe

NuGet version (x.x.x.xxx):
4.1.0.2450

OS version:
Windows 10 Version 1607 (OS Build 14393.953)
Windows Server 2016 Datacenter Version 1607 (OS Build 14393.969)

Worked before? If so, with which NuGet version:
3.5.0.1938

Detailed repro steps so we can see the same problem

1. Create a new SPA application, using e.g. Aurelia, that depends on a huge amount of NPM packages that need to be deployed with the application.
2. Create a .nuspec file, including all files from for the unbundled SPA application using a path starting with ... This should include a large amount of small JS files.
3. Pack with NuGet 3.5.0 and 4.1.0 and compare time spent packing.

Other suggested things

• Small number of files to pack hides the issue.
• The issue doesn't happen when the include path doesn't start with ... That is:
  <file src="..\app\wwwroot\**\*.*" target="" /> will show the error but with
  <file src="wwwroot\**\*.*" target="" />, I was unable to reproduce the problem.

Workaround

Copy the files in a folder below the .nuspec file and include from there.

Verbose Logs

There's nothing special in the verbose logs, packing succeeds but just takes a lot of time on 4.1.0.

Sample Project

There's a Powershell script (repro.ps1)in this package to demonstrate the issue:
https://1drv.ms/u/s!ArvtSAxE-8DWitlqmMKfjzzFB94_Gw

[rohit21agrawal]

Looking at perfview Etl logs, i was able to confirm that this regressed as a result of : https://github.com/NuGet/NuGet.Client/pull/909

I will talk to @dtivel tomorrow about possible resolution strategies.

[rohit21agrawal]

had to revert change because of functional test failures

[serialskiller]

still not working

[serialskiller]

version 3.5:
nuget.exe pack example.nuspec # in process monitor io starts straight away
nuget 7.1:
~ 2 minutes to pack, eating up one cpu core and io happens at the end.
adding a basepath param helps a bit, removing exclude as well. Didn't have a look at the code, but maybe the globbing used is not very efficient? The current version can't be used with web projects!

[Genyus]

I just lost an entire day attempting to debug a new project build on our DevOps instance. A NuGet pack task (set up with 4.4.1) was timing out after an hour when building a package from a .nuspec file using both relative paths and excludes in a directory containing ~14K files and ~3K folders. After discovering this bug and switching the task to use 3.5.0, it now completes in ~40 seconds.

[brentapex]

I have this issue and not with relative paths. I have a fairly large and complex file structure I want to pack into a nuget package. I use a nuspec file. The file command is very similar to what I use in an inno setup script. Inno setup can package up the entire directory structure in a matter of seconds. Nuget is taking over an hour. I don't know what nuget is doing but it is doing it very badly.

[jussimattila]

Anything happening regarding this issue? Almost two years after reporting and having Priority 1, will this make into a release in the near future?

[jcoutch]

@rohit21agrawal / @dtivel - Are there any plans to fix this bug?

[Sellec]

@rohit21agrawal / @dtivel - Are there any plans to fix this bug?

Im joining your question. Its too long to wait over 20 minutes while it packs 957 files into usual and symbol packages.

[dtivel]

We do not have plans to fix this in the upcoming 5.3 release; however, we will reevaluate this bug for the following release.

[ajweitz]

We do not have plans to fix this in the upcoming 5.3 release; however, we will reevaluate this bug for the following release.

Will it be fixed in the next release?
Nuget 3.5 lacks some features thus making nuget almost unusable in some scenarios.

[luis-echegaray]

The github registry feature requires the repository metadata which 3.5 does not support, so now we have to choose between continuing with Github Registry with 40 minute packaging steps, or head back to Nexus3
:(

[dtivel]

I have a PR out for NuGet 5.5 that improves pack performance significantly, though still not back to 3.5.0 baseline. See that PR for details.

The PR addresses the main problem affecting the repro in this issue. There may be more opportunities for improving performance, but not as significant as this one.

This area of the code is complicated, fragile, and buggy. NuGet's file patterns are globbing-like but non-standard. Making changes in this area tends to be costly and risky.

In terms of maintainability, standardization, and performance, a better solution would be to move to Microsoft.Extensions.FileSystemGlobbing for file system globbing, but there's a high probability it would break some non-standard NuGet globbing-like patterns in use.

[serialskiller]

Zipping a web folder takes over 10 min & eats up a whole cpu core:

This is a PACKER it should pack!
I switch back to plain zip & upload to a maven repository as the developers I have to support are not amused!

[serialskiller]

It happens with absolute path as well:
src=C:\tools\tmp\xxxbin\Releasenetcoreapp2.2\publish\**"
target="Content"
exclude="*.vshost.exe;*.vshost.exe.manifest;*.vshost.exe.config;.csproj;.csproj.user;.nuspec;obj*;web..config;*.cs;***.RoslynCA.json"

[karann-msft]

hey @serialskiller - have you tried out your scenario with the latest nuget.exe 5.4? I am hoping @dtivel's fix improved the scenario.

[Sellec]

hey @serialskiller - have you tried out your scenario with the latest nuget.exe 5.4? I am hoping @dtivel's fix improved the scenario.

No, it is not fixed.
I have tried this now with Visual Studio 2019 (VS 'About' form says it using NuGet 5.4), my project still packaging (started at 12:38 and still packaging at 13:00).
Total files with relative paths (placed not in project folder or project subfolders) are 1460.

[Sellec]

hey @serialskiller - have you tried out your scenario with the latest nuget.exe 5.4? I am hoping @dtivel's fix improved the scenario.

No, it is not fixed.
I have tried this now with Visual Studio 2019 (VS 'About' form says it using NuGet 5.4), my project still packaging (started at 12:38 and still packaging at 13:00).
Total files with relative paths (placed not in project folder or project subfolders) are 1460.

It takes ~13 minutes to build package with 1460 files. I have normal and symbols package and build time for each of them was ~13 minutes (13:39 -> 13:52 and 13:52 -> 14:06). Seems like resolving one relative path takes ~0.5 second for nuget pack task.

P.S. if i will manually copy all needed files into project subfolders and run build with pack, it takes ~1 minute to build both packages.
P.P.S. It was tested in Visual Studio Community 2019 v.16.4.5. (nuget version 5.4.0)

P.P.P.S my .csproj looks like this (sdk-style project does not allow me to use ASP.Net MVC with razor views and the solution is to use old-style project with all asp.net mvc code and to include this separate project output into sdk-style project which supports package building):
..\Library and ..\JS is the folders containing separate asp.net mvc project and nodejs front-end project with all needed js code.

    <Content Include="..\Library\Modules\**\*" Exclude="..\Library\**\*.cs">
      <Pack>true</Pack>
      <PackageCopyToOutput>true</PackageCopyToOutput>
      <PackageFlatten>false</PackageFlatten>
      <Link>Modules\%(RecursiveDir)%(Filename)%(Extension)</Link>
      <PackagePath>content\%(Link);contentFiles\any\$(TargetFramework)\%(Link)</PackagePath>
    </Content>
    <Content Include="..\JS\dist\**\*" Exclude="..\JS\dist\main.js">
      <Pack>true</Pack>
      <PackageCopyToOutput>true</PackageCopyToOutput>
      <PackageFlatten>false</PackageFlatten>
      <Link>Design\UI\%(RecursiveDir)%(Filename)%(Extension)</Link>
      <PackagePath>content\%(Link);contentFiles\any\$(TargetFramework)\%(Link)</PackagePath>
    </Content>

[Sellec]

As i can see, problem is in NuGet.Commands.PackCommandRunner.ExcludeFiles method.
It calls PathResolver.GetFilteredPackageFiles<..>(..) and removes all files matching specific patterns from pack input files list.

internal void ExcludeFiles(ICollection<IPackageFile> packageFiles)
{
    IEnumerable<string> enumerable = this._excludes.Concat(new string[]
    {
        "**\\*" + NuGetConstants.ManifestExtension
    });
    if (!this._packArgs.NoDefaultExcludes)
    {
        IEnumerable<IPackageFile> filteredPackageFiles = PathResolver.GetFilteredPackageFiles<IPackageFile>(packageFiles, new Func<IPackageFile, string>(this.ResolvePath), PackCommandRunner._defaultExcludes);
        if (filteredPackageFiles != null)
        {
            foreach (IPackageFile current in filteredPackageFiles)
            {
                if (current is PhysicalPackageFile)
                {
                    PhysicalPackageFile physicalPackageFile = current as PhysicalPackageFile;
                    this._packArgs.Logger.Log(PackagingLogMessage.CreateWarning(string.Format(CultureInfo.CurrentCulture, Strings.Warning_FileExcludedByDefault, physicalPackageFile.SourcePath), NuGetLogCode.NU5119));
                }
            }
        }
    }
    enumerable = enumerable.Concat(this._packArgs.Exclude);
    PathResolver.FilterPackageFiles<IPackageFile>(packageFiles, new Func<IPackageFile, string>(this.ResolvePath), enumerable);
}

The one way to reduce packing time to 50% is to set to true the project property NoDefaultExcludes.

<NoDefaultExcludes>true</NoDefaultExcludes>

But it would definetely call PathResolver.FilterPackageFiles at the end of the method and it would do the slow job with all your files...
Maybe the problem is in NuGet.Commands.PackCommandRunner.ResolvePath method which prepares path of every file in list.
This parts of code was not changed between 4.9.0 and 5.4.0.2.

[Sellec]

Problem is partially solved.
My projects structure looks like this:
--AspNetMvc
----JS
----Library
----Package
So, if the problem of long packaging is in checking relative paths and nuget pack task uses $(NuspecBasePath) as a basePath in NuGet.Commands.PackCommandRunner.ResolvePath, i tries to set $(NuspecBasePath) to AspNetMvc folder. Folders JS and Library starts to look like subfolders for $(NuspecBasePath) (in usual way they looks like ..\JS and ..\Library paths) and...packing process now is very fast.
You can add this target into your .csproj project file and all would work perfect.

  <Target Name="CreateNuspecBasePath" BeforeTargets="CoreCompile">
    <PropertyGroup>
     <NuspecBasePath>$([System.IO.Path]::GetFullPath('$(ProjectDir)..'))</NuspecBasePath>
    </PropertyGroup>
  </Target>

P.S. Seems like it would not work is you really need to use $(NuspecBasePath) for setting nuspec path and it is not placed under your relative paths, or if files, included into your project are placed too far from project folder (maybe in .nuget folder of current user profile).