crossgen2 failure in Performance Windows_NT x64 release

[tarekgh]

https://dev.azure.com/dnceng/public/_build/results?buildId=680954&view=logs&j=cd79c11a-657c-5f7d-cef4-0295f5c3e6e4&t=de8acb27-fceb-5259-64d5-cc0391919dd6&l=38. according to the report https://dev.azure.com/dnceng/public/_pipeline/analytics/stageawareoutcome?definitionId=783 it looks it is failed more than 33 times today.

[jkotas]

Crossgen2 is failing:

[2020/06/10 19:08:03][INFO] ----------------------------------------------
[2020/06/10 19:08:03][INFO] Initializing logger 2020-06-10 19:08:03.005980
[2020/06/10 19:08:03][INFO] ----------------------------------------------
[2020/06/10 19:08:03][INFO] $ C:\h\w\AB430986\w\B3F709C3\u\startup\Startup.exe --app-exe C:\h\w\AB430986\p\Core_Root\CoreRun.exe --metric-type Crossgen2 --trace-name "Crossgen2 Throughput - Composite - framework-r2r_startup" --gui-app false --process-will-exit true --iterations 1 --timeout 1800 --warmup true --working-dir C:\h\w\AB430986\p\Core_Root --report-json-path traces\perf-lab-report.json --trace-directory traces --scenario-name "Crossgen2 Throughput - Composite - framework-r2r" --app-args "crossgen2\crossgen2.dll --composite -o C:\h\w\AB430986\p\Core_Root\composite.out\framework-r2r.ni.dll -O @C:\h\w\AB430986\p\performance\src\scenarios\crossgen2\framework-r2r.dll.rsp" --skip-profile-iteration
[2020/06/10 19:08:05][INFO] Running C:\h\w\AB430986\p\Core_Root\CoreRun.exe (args: "crossgen2\crossgen2.dll --composite -o C:\h\w\AB430986\p\Core_Root\composite.out\framework-r2r.ni.dll -O @C:\h\w\AB430986\p\performance\src\scenarios\crossgen2\framework-r2r.dll.rsp")
[2020/06/10 19:08:05][INFO] Working Directory: C:\h\w\AB430986\p\Core_Root
[2020/06/10 19:08:05][INFO] Iteration set up:  (args: )
[2020/06/10 19:08:05][INFO] Iteration clean up:  (args: )
[2020/06/10 19:08:05][INFO] =============== Warm up ================
[2020/06/10 19:08:05][INFO] ***Test***
[2020/06/10 19:08:06][INFO] 
[2020/06/10 19:08:06][INFO] 
[2020/06/10 19:08:06][INFO] Process 2200 failed to run. Result: ExitedWithError
[2020/06/10 19:08:06][ERROR] Process exited with status 4294967295
Traceback (most recent call last):
  File "C:\h\w\AB430986\p\performance\src\scenarios\crossgen2\test.py", line 16, in <module>
    Runner(traits).run()
  File "C:\h\w\AB430986\w\B3F709C3\u\shared\runner.py", line 225, in run
    startup.runtests(self.traits)
  File "C:\h\w\AB430986\w\B3F709C3\u\shared\startup.py", line 100, in runtests
    RunCommand(startup_args, verbose=True).run()
  File "C:\h\w\AB430986\w\B3F709C3\u\scripts\performance\common.py", line 200, in run
    returncode, quoted_cmdline)
subprocess.CalledProcessError: Command '$ C:\h\w\AB430986\w\B3F709C3\u\startup\Startup.exe --app-exe C:\h\w\AB430986\p\Core_Root\CoreRun.exe --metric-type Crossgen2 --trace-name "Crossgen2 Throughput - Composite - framework-r2r_startup" --gui-app false --process-will-exit true --iterations 1 --timeout 1800 --warmup true --working-dir C:\h\w\AB430986\p\Core_Root --report-json-path traces\perf-lab-report.json --trace-directory traces --scenario-name "Crossgen2 Throughput - Composite - framework-r2r" --app-args "crossgen2\crossgen2.dll --composite -o C:\h\w\AB430986\p\Core_Root\composite.out\framework-r2r.ni.dll -O @C:\h\w\AB430986\p\performance\src\scenarios\crossgen2\framework-r2r.dll.rsp" --skip-profile-iteration' returned non-zero exit status 4294967295.

C:\h\w\AB430986\w\B3F709C3\e>set _commandExitCode=1 

cc @dotnet/crossgen-contrib

[mangod9]

@ooooolivia was looking at a similar failure yesterday.

[trylek]

When I investigated the failure yesterday, I noticed two runs from about 2 days back where the test failed like this (after the last green run); after that it started to fail compiling due to a missing dependency - that's what I believe Olivia fixed yesterday and it's possible that with that fix the runs are now back to "the first error".

[ooooolivia]

This is crossgen2 perf test (crossgen2 composite scenario) that has already been turned off. The error message is not logged (not sure why helix missed that) but here is the error message I found in another log:

[2020/06/11 18:16:58][INFO] Initializing logger 2020-06-11 18:16:58.506398
[2020/06/11 18:16:58][INFO] ----------------------------------------------
[2020/06/11 18:16:58][INFO] $ C:\h\w\B0D70A10\w\A1AE0918\u\startup\Startup.exe --app-exe C:\h\w\B0D70A10\p\Core_Root\CoreRun.exe --metric-type Crossgen2 --trace-name "Crossgen2 Throughput - Composite - framework-r2r_startup" --gui-app false --process-will-exit true --iterations 1 --timeout 1800 --warmup true --working-dir C:\h\w\B0D70A10\p\Core_Root --report-json-path traces\perf-lab-report.json --trace-directory traces --scenario-name "Crossgen2 Throughput - Composite - framework-r2r" --app-args "crossgen2\crossgen2.dll --composite -o C:\h\w\B0D70A10\p\Core_Root\composite.out\framework-r2r.ni.dll -O @C:\h\w\B0D70A10\p\performance\src\scenarios\crossgen2\framework-r2r.dll.rsp" --skip-profile-iteration
[2020/06/11 18:16:59][INFO] Running C:\h\w\B0D70A10\p\Core_Root\CoreRun.exe (args: "crossgen2\crossgen2.dll --composite -o C:\h\w\B0D70A10\p\Core_Root\composite.out\framework-r2r.ni.dll -O @C:\h\w\B0D70A10\p\performance\src\scenarios\crossgen2\framework-r2r.dll.rsp")
[2020/06/11 18:16:59][INFO] Working Directory: C:\h\w\B0D70A10\p\Core_Root
[2020/06/11 18:16:59][INFO] Iteration set up:  (args: )
[2020/06/11 18:16:59][INFO] Iteration clean up:  (args: )
[2020/06/11 18:16:59][INFO] =============== Warm up ================
[2020/06/11 18:16:59][INFO] ***Test***
[2020/06/11 18:17:01][INFO] 
[2020/06/11 18:17:01][INFO] Error: Module with same simple name already exists C:\h\w\B0D70A10\p\Core_Root\Microsoft.CodeAnalysis.VisualBasic.ni.dll
[2020/06/11 18:17:01][INFO] System.IO.FileNotFoundException: Module with same simple name already exists C:\h\w\B0D70A10\p\Core_Root\Microsoft.CodeAnalysis.VisualBasic.ni.dll
[2020/06/11 18:17:01][INFO]    at ILCompiler.CompilerTypeSystemContext.AddModule(String filePath, String expectedSimpleName, Boolean useForBinding) in /_/src/coreclr/src/tools/Common/Compiler/CompilerTypeSystemContext.cs:line 220
[2020/06/11 18:17:01][INFO]    at ILCompiler.CompilerTypeSystemContext.GetOrAddModuleFromPath(String filePath, Boolean useForBinding) in /_/src/coreclr/src/tools/Common/Compiler/CompilerTypeSystemContext.cs:line 146
[2020/06/11 18:17:01][INFO]    at ILCompiler.Program.Run() in /_/src/coreclr/src/tools/crossgen2/crossgen2/Program.cs:line 276
[2020/06/11 18:17:01][INFO]    at ILCompiler.Program.InnerMain(CommandLineOptions buildOptions) in /_/src/coreclr/src/tools/crossgen2/crossgen2/Program.cs:line 588
[2020/06/11 18:17:01][INFO] 
[2020/06/11 18:17:01][INFO] Process 5272 failed to run. Result: ExitedWithError
[2020/06/11 18:17:01][ERROR] Process exited with status 4294967295
Traceback (most recent call last):
  File "C:\h\w\B0D70A10\p\performance\src\scenarios\crossgen2\test.py", line 16, in <module>
    Runner(traits).run()
  File "C:\h\w\B0D70A10\w\A1AE0918\u\shared\runner.py", line 225, in run
    startup.runtests(self.traits)
  File "C:\h\w\B0D70A10\w\A1AE0918\u\shared\startup.py", line 100, in runtests
    RunCommand(startup_args, verbose=True).run()
  File "C:\h\w\B0D70A10\w\A1AE0918\u\scripts\performance\common.py", line 200, in run
    returncode, quoted_cmdline)

[mangod9]

assume this issue can be closed since the test is disabled currently?

[davidwrighton]

Do we have an understanding of what the fix is? If not, we should keep the issue open to track fixing whatever was wrong.

[nattress]

The existing crossgen1 perf tests just emit their native images into the core_root folder and it looks like they're getting picked up in the composite framework test which compiles Microsoft.*.dll. So we're passing both the dll and the crossgen ni.dll to crossgen2.

We should pass /out <filename> to crossgenargs here https://github.com/dotnet/performance/blob/0b9fa3e0fc7ee5377ba539957dc12062a63e1a7c/src/scenarios/shared/runner.py#L165 and put the output in a sub-directory or something.

[ooooolivia]

It seems the perfhelixpublish.proj that triggers perf crossgen2 perf jobs has been overriden by arcade change, so the workitem has been reverted. Will submit a new PR to disable it now. #37842