Windows Server 2019 20201108.1 breaks a build that works in 20201021.0

[MarkStega]

Description
A build of a dotnet project fails in 20201108.1

The csproj step that is failing is

  <Target Name="CheckIfNpmExists" Inputs="@(InputStaticAssetsScripts);@(InputStaticAssetsStyles)" Outputs="@(OutputStaticAssetsScripts);@(OutputStaticAssetsStyles)" BeforeTargets="PreBuildEvent">
    <Exec Command="echo ***** npm install" />
    <Exec Command="npm install" ContinueOnError="true" StandardOutputImportance="low" StandardErrorImportance="low" LogStandardErrorAsError="false" IgnoreExitCode="true">
      <Output TaskParameter="ExitCode" PropertyName="NpmReturnCode" />
    </Exec>
    <Exec Command="echo ***** 'npm install' return code was $(NpmReturnCode) (0 indicates npm is available)" />
  </Target>

My trace log shows

  ***** npm install
  ***** 'npm install' return code was 1 (0 indicates npm is available)

We have two developers collaborating and each has a fork of the repository in question

The developer with the failing run shows a virtual environment of

Virtual Environment
  Environment: windows-2019
  Version: 20201108.1
  Included Software: https://github.com/actions/virtual-environments/blob/win19/20201108.1/images/win/Windows2019-Readme.md

The developer whose fork build successfully (with all else the same) has

Virtual Environment
  Environment: windows-2019
  Version: 20201021.0
  Included Software: https://github.com/actions/virtual-environments/blob/win19/20201021.0/images/win/Windows2019-Readme.md

The builds are running as GitHub actions

Area for Triage:

Scripting and command line

Question, Bug, or Feature?:

Bug

Virtual environments affected

• Ubuntu 16.04
• Ubuntu 18.04
• Ubuntu 20.04
• macOS 10.15
• macOS 11.0
• Windows Server 2016 R2
• [*] Windows Server 2019

Expected behavior
I expect the 1108.1 build to succeed as the 1021.1 build does.

Actual behavior
npm fails to run in the newer environment.

Repro steps

1. The repository can be found at https://github.com/Material-Blazor/Material.Blazor
2. Fork the repository
3. Push a change to the main branch
4. Observe the failure of the build triggered by the push (GitHubActionsWIP.yaml is the WF file).
5. Force the earlier environment (I don't know how to do this but if I did it would be a suitable workaround until the error is fixed)
6. Push the change
7. Observe a successful build

[maxim-lobanov]

@MarkStega , I guess you are affected by this change: #1953.
Could you please try to follow mitigation ways to see if it helps?

[MarkStega]

It does not help

Run actions/setup-node@v1
  with:
    node-version: 12
    always-auth: false
  env:
    buildPlatform: Any CPU
    buildConfiguration: Release
    outputDocFx: D:\a\Material.Blazor\Material.Blazor\siteDocFx
    outputMB: D:\a\Material.Blazor\Material.Blazor\siteMB
    outputWeb: D:\a\Material.Blazor\Material.Blazor\siteWeb
    projectMB: Material.Blazor/Material.Blazor.csproj
    projectWeb: Material.Blazor.Website.WebAssembly/Material.Blazor.Website.WebAssembly.csproj
    ciSuffix: ci.2020-11-11--1511
C:\hostedtoolcache\windows\node\12.19.0\x64\node.exe --version
v12.19.0
C:\windows\system32\cmd.exe /D /S /C "C:\hostedtoolcache\windows\node\12.19.0\x64\npm.cmd --version"
6.14.8

The build fails in the same fashion. I have Node 14.15.0 on my local system and the build has no difficulty invoking NPM

[MarkStega]

I added trace of executing "node --version" and "npm --version"

Run node --version
v14.15.0
Run npm --version
6.14.8

So something is keeping the dotnet build from accessing npm in this latest environment

[MarkStega]

I really do not understand what is going on. I removed the trace so I was back to the identical workflow file & source as during the failed build. Now the build succeeds. Are the virtual-environments used by github actions somehow cached & possibly incomplete? This is as if the image that was failing somehow did not have npm available but the same numbered image does.

Certainly I've shown (and have the logs) that github actions is not 100% reliable.

[maxim-lobanov]

@MarkStega , I have looked at your issue and found that issue is related to your changes. Actually, exit code 1 meant that npm fails to install dependency. Your builds started to pass after this commit: simonziegler/Material.Blazor@13e9936
In this commit, you have updated package-lock.json file and updated url https://registry.npmjs.org/is-number/-/is-number-8.0.0.tgz to https://registry.npmjs.org/is-number/-/is-number-7.0.0.tgz. If you try to check those urls, you will see that first url is invalid and NPM was not able to install your dependencies

P.S
I think that your current validation code is not convenient for debugging. It is pretty unclear where this exit code come from. It can be returned by CMD shell, also it can be returned by npm itself because it fails to install some dependency.

<Exec Command="npm install" ContinueOnError="true" StandardOutputImportance="low" StandardErrorImportance="low" LogStandardErrorAsError="false" IgnoreExitCode="true">
  <Output TaskParameter="ExitCode" PropertyName="NpmReturnCode" />
</Exec>

Exit code 1 doesn't mean that NPM is not available in environment. If npm is not found, exit code will be 9009. You can easily check it by replacing npm install by something like npm_invalid_binary_name install.

I suggest improving your code to catch command output in task and print it to logs. In this case, you will see exact error message and it will help debug issue.

[MarkStega]

Maxim,

Thanks for the help and taking the time to fully unravel the mystery; I made the bad assumption that a non-zero code meant that npm was not present. I'll change my logging to indicate "0 - npm present & successful, 1 - npm probable bad dependencies, 9009 - npm not present"; It is not clear to me why the package-lock.json committed by Simon was wrong and why it got corrected by me checking out his branch and doing builds. It is why I personally hate the trainwreck that is node/npm/js development.

[MarkStega]

@maxim-lobanov

I probably went overboard, but when it happens to me again 6 months from now I'll not make the same wrong assumption

  <Target Name="ErrorOutput" BeforeTargets="PreBuildEvent" AfterTargets="CheckIfNpmExists" Condition=" '$(NpmReturnCode)' != '0' ">
    <Exec Command="echo **********************************************************************************" />
    <Exec Command="echo **********************************************************************************" />
    <Exec Command="echo **********************************************************************************" />
    <Exec Command="echo CSS and JS not built due to the lack of a proper development environment" />
    <Exec Command="echo See https://material-blazor.com/docs/articles/DevelopmentEnvironment.html" />
    <Exec Command="echo If the return code is 1, check package.json and package-lock.json" />
    <Exec Command="echo If the return code is 9009, npm is not present" />
    <Exec Command="echo For other non-zero return codes, check npm documentation" />
    <Exec Command="echo **********************************************************************************" />
    <Exec Command="echo **********************************************************************************" />
    <Exec Command="echo **********************************************************************************" />
  </Target>

And it was a manual edit of the package-lock.json that started this whole issue.

[maxim-lobanov]

@MarkStega , cool, I am going to close an issue. Please let me know if you have any concerns.

P.S. I don't have much experience with msbuild but I guess we can do something like that:

<Exec Command="npm install" ConsoleToMsBuild="true" ContinueOnError="true" StandardOutputImportance="low" StandardErrorImportance="low" LogStandardErrorAsError="false" IgnoreExitCode="true">
  <Output TaskParameter="ConsoleOutput" PropertyName="NpmOutput" />
  <Output TaskParameter="ExitCode" PropertyName="NpmReturnCode" />
</Exec>
<Exec Command="echo ***** 'npm install' return code was $(NpmReturnCode) (0 indicates npm is available)" />
<Exec Command="echo ***** Output: $(NpmOutput)" Condition=" '$(NpmReturnCode)' != '0' " />

It should print command output to build log if exit code != 0 and you will see exact error message in addition to exit code