Msbuild: any NPM command is super slow 1+ minute
Literally any NPM command executed by msbuild is super slow. E.g. npm -v takes 70 seconds.
If I execute npm -v just from command line - it takes 1 second.
The problem is only happening for NPM. Yarn works fine.
Same slowness is happening if I execute any npm command from Visual Studio Immediate Power Shell panel.
Steps to reproduce
testNpm.proj
<Project xmlns="http://schemas.microsoft.com/developer/msbuild/2003">
<Target Name="SpaBuild" BeforeTargets="Build">
<Exec Command="npm --version" ContinueOnError="true" />
</Target>
</Project>
Directory contents:
/
- testNpm.proj
Command line
Actual behavior
...
Project "c:\!delme\test\testNpm.proj" on node 1 (default targets).
SpaBuild:
npm --version
6.5.0
Done Building Project "...\testNpm.proj" (default targets).
...
Time Elapsed 00:01:09.50
Expected behavior
Time Elapsed 00:00:01.00
...
Environment data
msbuild /version output:
Microsoft (R) Build Engine version 14.0.23107.0
OS info: Windows 10 x64 Pro, Windows 7 x64 pro
Visual Studio Pro 2017 v15.9.7
pmunin
All 14 comments
That's very odd! I do not see the same behavior:
s:\msbuild>msbuild S:\repro\Microsoft\msbuild\issues\4178\testNpm.proj
Microsoft (R) Build Engine version 15.9.21+g9802d43bc3 for .NET Framework
Copyright (C) Microsoft Corporation. All rights reserved.
Build started 2/15/2019 10:29:38 AM.
Project "S:\repro\Microsoft\msbuild\issues\4178\testNpm.proj" on node 1 (default targets).
SpaBuild:
npm --version
5.6.0
Done Building Project "S:\repro\Microsoft\msbuild\issues\4178\testNpm.proj" (default targets).
Build succeeded.
0 Warning(s)
0 Error(s)
Time Elapsed 00:00:02.44
s:\msbuild>powershell measure-command {npm --version}
Days : 0
Hours : 0
Minutes : 0
Seconds : 2
Milliseconds : 108
Ticks : 21088718
TotalDays : 2.44082384259259E-05
TotalHours : 0.000585797722222222
TotalMinutes : 0.0351478633333333
TotalSeconds : 2.1088718
TotalMilliseconds : 2108.8718
One odd thing I notice about your post: you mention VS 2017, but have an MSBuild version 14.0.23107.0, which is an old VS 2015 version. But on my machine with 14.0.25402.0 I don't see a slowdown either.
Can you capture a binary log of the execution? What happens if you wrap the npm command with powershell like so?
diff --git a/testNpm.proj b/testNpm.proj
index 581c87f..f3171e7 100644
--- a/testNpm.proj
+++ b/testNpm.proj
@@ -1,5 +1,5 @@
<Project xmlns="http://schemas.microsoft.com/developer/msbuild/2003">
<Target Name="SpaBuild" BeforeTargets="Build">
- <Exec Command="npm --version" ContinueOnError="true" />
+ <Exec Command="powershell -NoProfile measure-command {npm --version}" ContinueOnError="true" />
</Target>
</Project>
rainersigwald
on 15 Feb 2019
Same problem here. This occures since npm update (previous Version 3.10) to Version 6.
10> Days : 0
10> Hours : 0
10> Minutes : 1
10> Seconds : 8
10> Milliseconds : 808
10> Ticks : 688089843
10> TotalDays : 0,00079640028125
10> TotalHours : 0,01911360675
10> TotalMinutes : 1,146816405
10> TotalSeconds : 68,8089843
10> TotalMilliseconds : 68808,9843
Fruchuxs
on 4 Mar 2019
this behavior happened at my work where we have proxy servers. Also it is not very inconsistent. And was gone on 2 different workstations by adding ".npmrc" file with proxy settings. to the project and then deleting it - the problem was gone for entire machine (other projects didn't have issue after that) 馃槙
@Fruchuxs can you try if this works for you?
pmunin
on 8 Mar 2019
I just tried to configure the proxy. I also tried your suggestion but didn't work. Without Exec, so with the task runner before build binding, it works fine.
Fruchuxs
on 8 Mar 2019
I appear to have failed to post my followup, but I still can't reproduce this:
S:\repro\Microsoft\msbuild\issues\4178>npm --version
6.8.0
S:\repro\Microsoft\msbuild\issues\4178>powershell -NoProfile measure-command {npm --version}
Days : 0
Hours : 0
Minutes : 0
Seconds : 2
Milliseconds : 73
Ticks : 20739097
TotalDays : 2.40035844907407E-05
TotalHours : 0.000576086027777778
TotalMinutes : 0.0345651616666667
TotalSeconds : 2.0739097
TotalMilliseconds : 2073.9097
S:\repro\Microsoft\msbuild\issues\4178>"C:\Program Files (x86)\Microsoft Visual Studio\Preview\Enterprise\MSBuild\15.0\Bin\MSBuild.exe"
Microsoft (R) Build Engine version 15.9.21+g9802d43bc3 for .NET Framework
Copyright (C) Microsoft Corporation. All rights reserved.
Build started 3/8/2019 9:48:19 AM.
Project "S:\repro\Microsoft\msbuild\issues\4178\testNpm.proj" on node 1 (default targets).
SpaBuild:
npm --version
6.8.0
Done Building Project "S:\repro\Microsoft\msbuild\issues\4178\testNpm.proj" (default targets).
Build succeeded.
0 Warning(s)
0 Error(s)
Time Elapsed 00:00:02.73
Without Exec, so with the task runner before build binding, it works fine.
Can you elaborate on this, please? What do you mean by "with the task runner before build binding"?
rainersigwald
on 8 Mar 2019
Can you elaborate on this, please? What do you mean by "with the task runner before build binding"?
Visual Studio Task Runner.
Fruchuxs
on 18 Mar 2019
@rainersigwald sorry missed your suggestions. wrapping build command in powershell didn't change anything - still takes 1+ minute to execute the npm --version command under msbuild, it actually takes 3 minutes for me now:
**********************************************************************
** Visual Studio 2017 Developer Command Prompt v15.9.9
** Copyright (c) 2017 Microsoft Corporation
**********************************************************************
C:\Program Files (x86)\Microsoft Visual Studio\2017\Professional>cd c:\temp\msbuild_4178\
c:\temp\msbuild_4178>msbuild
Microsoft (R) Build Engine version 15.9.21+g9802d43bc3 for .NET Framework
Copyright (C) Microsoft Corporation. All rights reserved.
Build started 3/20/2019 3:49:48 PM.
Project "c:\temp\msbuild_4178\testNpm.proj" on node 1 (default targets).
SpaBuild:
powershell -NoProfile measure-command {npm --version}
Days : 0
Hours : 0
Minutes : 3
Seconds : 9
Milliseconds : 409
Ticks : 1894095632
TotalDays : 0.00219224031481481
TotalHours : 0.0526137675555556
TotalMinutes : 3.15682605333333
TotalSeconds : 189.4095632
TotalMilliseconds : 189409.5632
Done Building Project "c:\temp\msbuild_4178\testNpm.proj" (default targets).
Build succeeded.
0 Warning(s)
0 Error(s)
Time Elapsed 00:03:10.01
Here is the output with /bl option::
c:\temp\msbuild_4178>msbuild /bl
Microsoft (R) Build Engine version 15.9.21+g9802d43bc3 for .NET Framework
Copyright (C) Microsoft Corporation. All rights reserved.
C:\Program Files (x86)\Microsoft Visual Studio\2017\Professional\MSBuild\15.0\bin\msbuild.exe /bl .\testNpm.proj
Build started 3/20/2019 3:54:17 PM.
Project "c:\temp\msbuild_4178\testNpm.proj" on node 1 (default targets).
SpaBuild:
powershell -NoProfile measure-command {npm --version}
Days : 0
Hours : 0
Minutes : 3
Seconds : 9
Milliseconds : 388
Ticks : 1893889818
TotalDays : 0.00219200210416667
TotalHours : 0.0526080505
TotalMinutes : 3.15648303
TotalSeconds : 189.3889818
TotalMilliseconds : 189388.9818
Done Building Project "c:\temp\msbuild_4178\testNpm.proj" (default targets).
Deferred Messages
Detailed Build Summary
======================
============================== Build Hierarchy (IDs represent configurations) =======================================
==============
Id : Exclusive Time Total Time Path (Targets)
---------------------------------------------------------------------------------------------------------------------
--------------
0 : 189.837s 189.837s c:\temp\msbuild_4178\testNpm.proj ()
============================== Node Utilization (IDs represent configurations) ======================================
==============
Timestamp: 1 Duration Cumulative
---------------------------------------------------------------------------------------------------------------------
--------------
636887084576364121: 0 189.837s 189.837s ################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#####################################################################################################################
#########################################################################################################
---------------------------------------------------------------------------------------------------------------------
--------------
Utilization: 100.0 Average Utilization: 100.0
Build succeeded.
0 Warning(s)
0 Error(s)
Time Elapsed 00:03:09.85
Here is the bin log itself:
pmunin
on 20 Mar 2019
Could it be that you are hitting https://github.com/npm/npm/issues/20979 ?
One of the workarounds is to set environment variable NO_UPDATE_NOTIFIER=1, does that solve your problem?
japj
on 7 Apr 2019
just set that var and npm --version takes less than a second now! thanks @japj !
pmunin
on 7 Apr 2019
Great to hear!
Can you close this issue now that it is resolved?
japj
on 8 Apr 2019
Awesome, thanks @japj!
rainersigwald
on 8 Apr 2019
How I can set it by parameter? This doesn't work:
npm install --no-update-notifier
npm run build --no-update-notifier
The Enivornment variable works fine, but can't put it into svn. :p
Fruchuxs
on 10 Apr 2019
You can set environment variables in the Exec task invocation:
<Exec Command="npm --version"
ContinueOnError="true"
EnvironmentVariables="NO_UPDATE_NOTIFIER=1" />
That's one of the task parameters common to many tasks.
rainersigwald
on 10 Apr 2019
Related issues
dsplaisted
路
42Comments
kg
路
38Comments
ariccio
路
78Comments
nguerrera
路
79Comments
tmat
路
53Comments
Most helpful comment
Could it be that you are hitting https://github.com/npm/npm/issues/20979 ?
One of the workarounds is to set environment variable NO_UPDATE_NOTIFIER=1, does that solve your problem?