Public Performance-CI Pipeline sdk_scenarios are failing due to Inner Loop MSBuild issue #2215
Description
https://dev.azure.com/dnceng/public/_build/results?buildId=1558138&view=results
The Inner Loop MSBuild Console Startup case is failing when trying to parse the resulting tracing files:
'''
[2022/01/18 17:46:28][INFO] =============== Iteration - Diff ================
[2022/01/18 17:46:31][INFO] Hello World2!
[2022/01/18 17:46:31][INFO]
[2022/01/18 17:46:31][INFO]
[2022/01/18 17:46:31][INFO] Iteration Cleanup
[2022/01/18 17:46:31][INFO]
[2022/01/18 17:46:31][INFO] [2022/01/18 17:46:31][INFO] ----------------------------------------------
[2022/01/18 17:46:31][INFO] [2022/01/18 17:46:31][INFO] Initializing logger 2022-01-18 17:46:31.714327
[2022/01/18 17:46:31][INFO] [2022/01/18 17:46:31][INFO] ----------------------------------------------
[2022/01/18 17:46:31][INFO] [2022/01/18 17:46:31][INFO] Removing project directory...
[2022/01/18 17:46:31][INFO]
[2022/01/18 17:46:31][INFO] Merging traces\Inner Loop MsBuild Console_startup.perflabkernel.etl,traces\Inner Loop MsBuild Console_startup.perflabuser.etl...
[2022/01/18 17:46:32][INFO] Trace Saved to traces\Inner Loop MsBuild Console_startup.etl
[2022/01/18 17:46:32][INFO] Parsing traces\Inner Loop MsBuild Console_startup.etl
[2022/01/18 17:46:34][INFO] Unhandled exception: System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation.
[2022/01/18 17:46:34][INFO] ---> System.Collections.Generic.KeyNotFoundException: The given key 'Evaluate/Stop' was not present in the dictionary.
[2022/01/18 17:46:34][INFO] at ScenarioMeasurement.InnerLoopMsBuildParser.Parse(String mergeTraceFile, String processName, IList1 pids, String commandLine) in D:\a\1\s\src\tools\ScenarioMeasurement\Startup\InnerLoopMsBuildParser.cs:line 161 [2022/01/18 17:46:34][INFO] at ScenarioMeasurement.Startup.Main(String appExe, MetricType metricType, String scenarioName, String traceName, Boolean processWillExit, Int32 iterations, String iterationSetup, String setupArgs, String iterationCleanup, String cleanupArgs, Int32 timeout, Int32 measurementDelay, String appArgs, String logFileName, String workingDir, Boolean warmup, Boolean guiApp, Boolean skipProfileIteration, String reportJsonPath, String traceDirectory, String environmentVariables, String innerLoopCommand, String innerLoopCommandArgs, Boolean runWithoutExit, Int32 hotReloadIters, Boolean skipMeasurementIteration, Boolean parseOnly) in D:\a\1\s\src\tools\ScenarioMeasurement\Startup\Startup.cs:line 336 [2022/01/18 17:46:34][INFO] --- End of inner exception stack trace --- [2022/01/18 17:46:34][INFO] at System.RuntimeMethodHandle.InvokeMethod(Object target, Span1& arguments, Signature sig, Boolean constructor, Boolean wrapExceptions)
[2022/01/18 17:46:34][INFO] at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)
[2022/01/18 17:46:34][INFO] at System.Reflection.MethodBase.Invoke(Object obj, Object[] parameters)
[2022/01/18 17:46:34][INFO] at System.CommandLine.Invocation.ModelBindingCommandHandler.InvokeAsync(InvocationContext context)
[2022/01/18 17:46:34][INFO] at System.CommandLine.Invocation.InvocationPipeline.<>c__DisplayClass4_0.<b__0>d.MoveNext()
[2022/01/18 17:46:34][INFO] --- End of stack trace from previous location ---
[2022/01/18 17:46:34][INFO] at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<b__19_0>d.MoveNext()
[2022/01/18 17:46:34][INFO] --- End of stack trace from previous location ---
[2022/01/18 17:46:34][INFO] at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass14_0.<b__0>d.MoveNext()
[2022/01/18 17:46:34][INFO] --- End of stack trace from previous location ---
[2022/01/18 17:46:34][INFO] at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass22_0.<b__0>d.MoveNext()
[2022/01/18 17:46:34][INFO] --- End of stack trace from previous location ---
[2022/01/18 17:46:34][INFO] at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass21_0.<b__0>d.MoveNext()
[2022/01/18 17:46:34][INFO] --- End of stack trace from previous location ---
[2022/01/18 17:46:34][INFO] at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<b__20_0>d.MoveNext()
[2022/01/18 17:46:34][INFO] --- End of stack trace from previous location ---
[2022/01/18 17:46:34][INFO] at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<b__18_0>d.MoveNext()
[2022/01/18 17:46:34][INFO] --- End of stack trace from previous location ---
[2022/01/18 17:46:34][INFO] at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<b__10_0>d.MoveNext()
[2022/01/18 17:46:34][INFO] --- End of stack trace from previous location ---
[2022/01/18 17:46:34][INFO] at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<b__9_0>d.MoveNext()
[2022/01/18 17:46:34][INFO] --- End of stack trace from previous location ---
[2022/01/18 17:46:34][INFO] at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass5_0.<b__0>d.MoveNext()
[2022/01/18 17:46:34][INFO] --- End of stack trace from previous location ---
[2022/01/18 17:46:34][INFO] at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass12_0.<b__0>d.MoveNext()
[2022/01/18 17:46:34][ERROR] Process exited with status 1
[2022/01/18 17:46:34][INFO] Run failure registered
Traceback (most recent call last):
File "C:\h\w\AE06095F\w\B86D0A69\e\test.py", line 16, in
Runner(traits).run()
File "C:\h\w\AE06095F\p\shared\runner.py", line 185, in run
startup.runtests(self.traits)
File "C:\h\w\AE06095F\p\shared\startup.py", line 150, in runtests
RunCommand(startup_args, verbose=True).run()
File "C:\h\w\AE06095F\p\scripts\performance\common.py", line 226, in run
raise CalledProcessError(
subprocess.CalledProcessError: Command '$ C:\h\w\AE06095F\p\startup\Startup.exe --app-exe dotnet --metric-type InnerLoopMsBuild --trace-name "Inner Loop MsBuild Console_startup" --gui-app false --process-will-exit true --iterations 1 --timeout 50 --warmup true --working-dir C:\h\w\AE06095F\w\B86D0A69\e --report-json-path traces\perf-lab-report.json --trace-directory traces --scenario-name "Inner Loop MsBuild Console" --app-args "run --project app\emptyconsoletemplateinnerloop.csproj" --iteration-setup py --setup-args "-3 C:\h\w\AE06095F\p\shared\sdk_iteration_setup.py setup_build" --iteration-cleanup py --cleanup-args "-3 C:\h\w\AE06095F\p\shared\sdk_iteration_setup.py cleanup" --inner-loop-command py --inner-loop-command-args "-c "from shutil import copyfile; copyfile('src\Program.cs', 'app\Program.cs')""' returned non-zero exit status 1.
'''
This appears to have started after Janurary 6th when the dotnet version being used changed from 7.0.100-alpha.1.21568.2 to 7.0.100-alpha.1.22057.7, and there a not any obvious changes to the perf repo that would cause this issue.