search

microsoft / vstest

Visual Studio Test Platform is the runner and engine that powers test explorer and vstest.console.
MIT License
902 stars 323 forks source link

Endless loop of AmbiguousMatchException with 16.6.0 #2408

Closed elmarb closed 4 years ago

elmarb commented 4 years ago

Description

Our Azure DevOps server pipeline hangs with endless repetitions of System.Reflection.AmbiguousMatchException in the "Visual Studio Test" task ever since 16.6.0 came out. We're trying to run Coded UI tests on Windows 10 machines (that don't do anything else). I realize it's easily worked around by fixing our "Visual Studio test platform installer" task at 16.5.0 rather than "latest stable".

Diagnostic logs

2020-04-20T16:11:14.3249862Z ##[section]Starting: Run Coded UI tests
2020-04-20T16:11:14.3470041Z ==============================================================================
2020-04-20T16:11:14.3470143Z Task         : Visual Studio Test
2020-04-20T16:11:14.3470200Z Description  : Run unit and functional tests (Selenium, Appium, Coded UI test, etc.) using the Visual Studio Test (VsTest) runner. Test frameworks that have a Visual Studio test adapter such as MsTest, xUnit, NUnit, Chutzpah (for JavaScript tests using QUnit, Mocha and Jasmine), etc. can be run. Tests can be distributed on multiple agents using this task (version 2).
2020-04-20T16:11:14.3470240Z Version      : 2.153.9
2020-04-20T16:11:14.3470275Z Author       : Microsoft Corporation
2020-04-20T16:11:14.3470337Z Help         : [More information](https://go.microsoft.com/fwlink/?LinkId=835764)
2020-04-20T16:11:14.3470684Z ==============================================================================
2020-04-20T16:11:15.6182386Z SystemVssConnection exists true
2020-04-20T16:11:15.6668508Z ##[warning]Unable to get feature flag: TestExecution.EnableHydra
2020-04-20T16:11:15.6689978Z SystemVssConnection exists true
2020-04-20T16:11:15.6980984Z ##[warning]Unable to get feature flag: TestExecution.EnableTranslationApi
2020-04-20T16:11:15.7223713Z SystemVssConnection exists true
2020-04-20T16:11:15.7526776Z ##[warning]Unable to get feature flag: TestExecution.EnableDiagnostics
2020-04-20T16:11:15.8356097Z In distributed testing flow
2020-04-20T16:11:15.8431898Z ======================================================
2020-04-20T16:11:15.8433051Z Test selector : Test run
2020-04-20T16:11:15.8433189Z Test run Id : '17239'
2020-04-20T16:11:15.8433324Z Search folder : C:\TVT\_UI_test
2020-04-20T16:11:16.1152134Z Distributed test execution, number of agents in job : 1
2020-04-20T16:11:16.1152746Z Run settings file : C:\TVT\_UI_test\videorecording.runsettings
2020-04-20T16:11:16.1153063Z Run in parallel : false
2020-04-20T16:11:16.1153173Z Run in isolation : false
2020-04-20T16:11:16.1153324Z Path to custom adapters : null
2020-04-20T16:11:16.1153620Z Other console options : null
2020-04-20T16:11:16.1153725Z Code coverage enabled : false
2020-04-20T16:11:16.1190259Z Diagnostics enabled : false
2020-04-20T16:11:16.2090839Z ======================================================
2020-04-20T16:11:16.2091841Z Source filter: **\*test*.dll,!**\*TestAdapter.dll,!**\obj\**
2020-04-20T16:11:16.6315105Z SystemVssConnection exists true
2020-04-20T16:11:16.6391454Z [command]C:\agent\_work\_tasks\VSTest_ef087383-ee5e-42c7-9a53-ab56c98420f9\2.153.9\Modules\DTAExecutionHost.exe --inputFile C:\agent\_work\_temp\input_904bfd40-8321-11ea-a694-75a70302d45c.json
2020-04-20T16:11:16.7915763Z ##########################################################################
2020-04-20T16:11:16.7920425Z DtaExecutionHost version 17.153.29006.1.
2020-04-20T16:11:16.8332930Z ##[warning]Updating HKCU\SOFTWARE\Microsoft\Windows\Windows Error Reporting\DontShowUI to 1 failed due to exception : System.NullReferenceException: Object reference not set to an instance of an object.
2020-04-20T16:11:16.8333843Z    at Microsoft.VisualStudio.TestService.Utility.WERRegistrySingleton.SetWERRegistryForHKCU()
2020-04-20T16:11:18.6058575Z ===========================================
2020-04-20T16:11:18.6059317Z AgentName: W10O19-7-Agent-W10O19-7-23
2020-04-20T16:11:18.6059691Z ServiceUrl: https:// REDACTED
2020-04-20T16:11:18.6059988Z TestPlatformVersion: 16.6.0
2020-04-20T16:11:18.6060264Z EnvironmentUri: vstest://env/Hase/_apis/release/2/1080/5206/1
2020-04-20T16:11:18.6060565Z QueryForTaskIntervalInMilliseconds: 3000
2020-04-20T16:11:18.6060843Z MaxQueryForTaskIntervalInMilliseconds: 10000
2020-04-20T16:11:18.6061155Z QueueNotFoundDelayTimeInMilliseconds: 3000
2020-04-20T16:11:18.6061699Z MaxQueueNotFoundDelayTimeInMilliseconds: 50000
2020-04-20T16:11:18.6062286Z ===========================================
2020-04-20T16:11:19.0973524Z TestExecutionHost.Execute: Registered TestAgent : 6435 : W10O19-7-Agent-W10O19-7-23
2020-04-20T16:11:19.1259284Z Provided settings file:
2020-04-20T16:11:19.1260276Z <?xml version="1.0" encoding="utf-8" ?>
2020-04-20T16:11:19.1260839Z <RunSettings>
2020-04-20T16:11:19.1261378Z   <!-- Configurations for data collectors -->
2020-04-20T16:11:19.1261901Z   <DataCollectionRunSettings>
2020-04-20T16:11:19.1262476Z     <DataCollectors>
2020-04-20T16:11:19.1262998Z       <!--Video data collector is only available with Visual Studio 2017 version 15.5 and higher -->
2020-04-20T16:11:19.1263586Z       <DataCollector uri="datacollector://microsoft/VideoRecorder/1.0" assemblyQualifiedName="Microsoft.VisualStudio.TestTools.DataCollection.VideoRecorder.VideoRecorderDataCollector, Microsoft.VisualStudio.TestTools.DataCollection.VideoRecorder, Version=15.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a" friendlyName="Screen and Voice Recorder">
2020-04-20T16:11:19.1264633Z         <Configuration>
2020-04-20T16:11:19.1265164Z           <MediaRecorder xmlns="">
2020-04-20T16:11:19.1265798Z             <!-- bitRate=500 is the minimum allowed by the GUI in the old MTM lab center test settings -->
2020-04-20T16:11:19.1266341Z             <ScreenCaptureVideo bitRate="500" frameRate="4" quality="60" />
2020-04-20T16:11:19.1266889Z           </MediaRecorder>
2020-04-20T16:11:19.1267464Z         </Configuration>
2020-04-20T16:11:19.1267826Z       </DataCollector>
2020-04-20T16:11:19.1268100Z     </DataCollectors>
2020-04-20T16:11:19.1268519Z   </DataCollectionRunSettings>
2020-04-20T16:11:19.1269071Z </RunSettings>
2020-04-20T16:11:19.1269537Z 
2020-04-20T16:11:19.1402956Z IsValidServiceResponse: Received None command..Service Workflow is not active
2020-04-20T16:11:19.1702490Z Updated Run Settings:
2020-04-20T16:11:19.1730233Z <RunSettings>
2020-04-20T16:11:19.1730961Z   <!-- Configurations for data collectors -->
2020-04-20T16:11:19.1731575Z   <DataCollectionRunSettings>
2020-04-20T16:11:19.1732140Z     <DataCollectors>
2020-04-20T16:11:19.1732730Z       <!--Video data collector is only available with Visual Studio 2017 version 15.5 and higher -->
2020-04-20T16:11:19.1733324Z       <DataCollector uri="datacollector://microsoft/VideoRecorder/1.0" assemblyQualifiedName="Microsoft.VisualStudio.TestTools.DataCollection.VideoRecorder.VideoRecorderDataCollector, Microsoft.VisualStudio.TestTools.DataCollection.VideoRecorder, Version=15.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a" friendlyName="Screen and Voice Recorder">
2020-04-20T16:11:19.1733865Z         <Configuration>
2020-04-20T16:11:19.1734361Z           <MediaRecorder xmlns="">
2020-04-20T16:11:19.1734908Z             <!-- bitRate=500 is the minimum allowed by the GUI in the old MTM lab center test settings -->
2020-04-20T16:11:19.1735490Z             <ScreenCaptureVideo bitRate="500" frameRate="4" quality="60" />
2020-04-20T16:11:19.1736104Z           </MediaRecorder>
2020-04-20T16:11:19.1736384Z         </Configuration>
2020-04-20T16:11:19.1736615Z       </DataCollector>
2020-04-20T16:11:19.1737715Z     </DataCollectors>
2020-04-20T16:11:19.1738348Z   </DataCollectionRunSettings>
2020-04-20T16:11:19.1738429Z   <RunConfiguration>
2020-04-20T16:11:19.1738483Z     <BatchSize>1000</BatchSize>
2020-04-20T16:11:19.1738561Z     <ResultsDirectory>C:\agent\_work\_temp\TR_54d2d8c9-4f9d-498c-8df9-c5ade45eaaa9</ResultsDirectory>
2020-04-20T16:11:19.1738613Z   </RunConfiguration>
2020-04-20T16:11:19.1738660Z </RunSettings>
2020-04-20T16:11:19.9066088Z Creating run for selected test assemblies with following parameters
2020-04-20T16:11:19.9066868Z SourceFilter: *.dll TestCaseFilter: 
2020-04-20T16:11:19.9067704Z test settings id : 13569
2020-04-20T16:11:19.9068113Z Run title: TestRun_TVT_UITest_selective_TVT_UITest_selective-374
2020-04-20T16:11:19.9068389Z Build location: C:\TVT\_UI_test
2020-04-20T16:11:19.9068704Z Build Id: 15081
2020-04-20T16:11:20.3538406Z Test run with Id 17239 associated
2020-04-20T16:11:30.1680211Z Received the command : Start
2020-04-20T16:11:30.1697427Z TestExecutionHost.ProcessCommand. Start Command handled
2020-04-20T16:11:31.3911156Z Slice with id = 60646, of type = 'Execution' received.
2020-04-20T16:11:31.4727591Z ##[error]An exception occurred while executing the task. So the task is not executed. System.Reflection.AmbiguousMatchException: Ambiguous match found.
2020-04-20T16:11:31.4728602Z    at System.RuntimeType.GetMethodImpl(String name, BindingFlags bindingAttr, Binder binder, CallingConventions callConv, Type[] types, ParameterModifier[] modifiers)
2020-04-20T16:11:31.4728903Z    at System.Type.GetMethod(String name, BindingFlags bindingAttr)
2020-04-20T16:11:31.4729176Z    at MS.VS.TestService.TestPlatform.Common.FakesUtilities.TryGetFakesDataCollectorConfigurator(Func`2& configurator)
2020-04-20T16:11:31.4729476Z    at MS.VS.TestService.TestPlatform.Common.FakesUtilities.TryAddFakesDataCollectorSettings(XmlDocument runSettings, String[] sources)
2020-04-20T16:11:31.4730795Z    at MS.VS.TestService.TestPlatform.Common.FakesUtilities.GenerateFakesSettingsForRunConfiguration(String[] sources, String runSettingsXml)
2020-04-20T16:11:31.4731096Z    at Microsoft.VisualStudio.TestService.VstestAdapter.RunDetailsStore.EnableFakes(String[] sources, String runSettings)
2020-04-20T16:11:31.4731394Z    at Microsoft.VisualStudio.TestService.VstestAdapter.RunDetailsStore.NormalizeSettings()
2020-04-20T16:11:31.4731656Z    at Microsoft.VisualStudio.TestService.VstestAdapter.RunDetailsStore.set_CurrentSliceDetails(TestAutomationRunSlice value)
2020-04-20T16:11:31.4731949Z    at Microsoft.VisualStudio.TestService.VstestAdapter.VstestAdapter.ExecuteAsync(ExecutionStateContext stateModelContext, CancellationToken cancellationToken, IProgress`1 progress)
2020-04-20T16:11:31.4732221Z    at Microsoft.VisualStudio.TestService.ExecutionStateModel.DistributedTestExecutionAgent.ExecuteCurrentPhase(CancellationToken cancellationToken)
more than 600000 repeating lines omitted
2020-04-20T16:12:41.0606187Z ##[error]The operation was canceled.
2020-04-20T16:12:41.0621017Z ##[section]Finishing: Run Coded UI tests

Environment

Server: Azure DevOps Server Version Dev17.M153.5 Agent: Name Value
Agent.Version 2.144.2
Agent.OSArchitecture X64
Agent.OSVersion 10.0.18362
DotNetFramework C:\Windows\Microsoft.NET\Framework64\v4.0.30319
DotNetFramework_4.7.0 C:\Windows\Microsoft.NET\Framework\v4.0.30319
DotNetFramework_4.7.0_x64 C:\Windows\Microsoft.NET\Framework64
InteractiveSession True
PowerShell 5.1.18362.145
tmilnthorp commented 4 years ago

Same issue. We have rolled back to 16.5.0

matsukawar commented 4 years ago

Same issue. Now, I use spesific version "16.6.0-preview-20200310-03". Previous versions has no probrems to run UnitTest program.

aDisplayName commented 4 years ago

Same issue. The previous run on 16.5.0 has no problem.

The tests using Test Assembly works fine with 16.6.0 But the tests using Test Plan testSelector: 'testPlan' just cannot make it. It happened to both of our pipelines using test plan.

nohwnd commented 4 years ago

Thanks for the report, I unlisted the 16.6.0 package while we investigate this.

@vritant24 could you jump on this please?

304NotModified commented 4 years ago

FYI:

I see 16.6.0 is unlisted on nuget.org

image

Unfortunalty Dependabot is pushing 16.6.0:

image

nohwnd commented 4 years ago

@304NotModified Thanks for the info, the fakes change should be limited to TestPlatform package, so this one should be safe to re-list (and it's dependencies). Validating that.

nohwnd commented 4 years ago

@304NotModified Re-listed, please let me know if you see more problems.

matsukawar commented 4 years ago

It works well now. thank you for your support.

2020年4月21日(火) 18:53 Jakub Jareš notifications@github.com:

@304NotModified https://github.com/304NotModified Re-listed, please let me know if you see more problems.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/microsoft/vstest/issues/2408#issuecomment-617077878, or unsubscribe https://github.com/notifications/unsubscribe-auth/AG7XBCDHHVIGFO77JBRB4CLRNVUKFANCNFSM4MMTVVMQ .

vritant24 commented 4 years ago

Fixed in #2417

vitalyve commented 4 years ago

Hi Our TFS DB has been increased 4 times in size during infinite loop. How can I safely clean it to reduce it's size to previous value?

nohwnd commented 4 years ago

@ShreyasRmsft do you have an answer for @vitalyve question please?

ShreyasRmsft commented 4 years ago

@vitalyve setting up a retention policy to clean up older builds should free up the size naturally. This is the recommended way.