aspnetcore: dotnet watch tests timing out

Pattern: Failing on Win10 arm64 builds for the last three days. Quarantined. https://dev.azure.com/dnceng/public/_build/results?buildId=765006&view=ms.vss-test-web.build-test-results-tab&runId=23772704&resultId=121076&paneView=debug https://dev.azure.com/dnceng/public/_build/results?buildId=766216&view=ms.vss-test-web.build-test-results-tab&runId=23810024&resultId=121079&paneView=debug https://dev.azure.com/dnceng/public/_build/results?buildId=766845&view=ms.vss-test-web.build-test-results-tab&runId=23842494&resultId=121106&paneView=debug

Microsoft.DotNet.Watcher.Tools.FunctionalTests.DotNetWatcherTests.RunsWithIterationEnvVariable Microsoft.DotNet.Watcher.Tools.FunctionalTests.NoDepsAppTests.RestartProcessThatTerminatesAfterFileChange

Dumps are attached to the build results.

System.Threading.Tasks.TaskCanceledException : A task was canceled.
   at Microsoft.DotNet.Watcher.Tools.FunctionalTests.AwaitableProcess.GetOutputLineAsync(String predicateName, Predicate`1 predicate, CancellationToken cancellationToken) in /_/src/Tools/dotnet-watch/test/AwaitableProcess.cs:line 103
   at Microsoft.DotNet.Watcher.Tools.FunctionalTests.AwaitableProcess.GetOutputLineAsync(String message, TimeSpan timeout) in /_/src/Tools/dotnet-watch/test/AwaitableProcess.cs:line 88
   at Microsoft.DotNet.Watcher.Tools.FunctionalTests.DotNetWatcherTests.RunsWithIterationEnvVariable() in /_/src/Tools/dotnet-watch/test/DotNetWatcherTests.cs:line 53
--- End of stack trace from previous location ---

[xUnit.net 00:03:56.73]         8/11/2020 5:22:20 PM: recv: 'watch : Started'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: 'MSBUILD : error MSB1025: An internal failure occurred while running MSBuild.'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: 'MSBUILD : error MSB1025: An internal failure occurred while running MSBuild.'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: 'System.Runtime.InteropServices.COMException (0x80004005): Unspecified error (0x80004005 (E_FAIL))'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at System.Runtime.InteropServices.GCHandle.InternalSet(IntPtr handle, Object value)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: 'System.Runtime.InteropServices.COMException (0x80004005): Unspecified error (0x80004005 (E_FAIL))'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at System.Runtime.InteropServices.GCHandle.InternalSet(IntPtr handle, Object value)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at System.Runtime.InteropServices.GCHandle.set_Target(Object value)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.WeakStringCache.GetOrCreateEntry[T](T internable, Boolean& cacheHit)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.OpportunisticIntern.WeakStringCacheInterner.TryIntern[T](T candidate, String& interned)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.OpportunisticIntern.WeakStringCacheInterner.InterningToString[T](T candidate)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.OpportunisticIntern.InternableToStringImpl[T](T candidate)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at System.Runtime.InteropServices.GCHandle.set_Target(Object value)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.Evaluation.Expander`2.ItemExpander.ExpandItemVectorsIntoString[T](Expander`2 expander, String expression, IItemProvider`1 items, ExpanderOptions options, IElementLocation elementLocation)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.Evaluation.Expander`2.ExpandIntoStringLeaveEscaped(String expression, ExpanderOptions options, IElementLocation elementLocation)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.BackEnd.ItemGroupIntrinsicTask.ExpandItemIntoItems(ProjectItemGroupTaskItemInstance originalItem, Expander`2 expander, ISet`1 keepMetadata, ISet`1 removeMetadata)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.WeakStringCache.GetOrCreateEntry[T](T internable, Boolean& cacheHit)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.OpportunisticIntern.WeakStringCacheInterner.TryIntern[T](T candidate, String& interned)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.OpportunisticIntern.WeakStringCacheInterner.InterningToString[T](T candidate)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.OpportunisticIntern.InternableToStringImpl[T](T candidate)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.Evaluation.Expander`2.ItemExpander.ExpandItemVectorsIntoString[T](Expander`2 expander, String expression, IItemProvider`1 items, ExpanderOptions options, IElementLocation elementLocation)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.BackEnd.ItemGroupIntrinsicTask.ExecuteAdd(ProjectItemGroupTaskItemInstance child, ItemBucket bucket, ISet`1 keepMetadata, ISet`1 removeMetadata)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.Evaluation.Expander`2.ExpandIntoStringLeaveEscaped(String expression, ExpanderOptions options, IElementLocation elementLocation)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.BackEnd.ItemGroupIntrinsicTask.ExecuteTask(Lookup lookup)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.BackEnd.ItemGroupIntrinsicTask.ExpandItemIntoItems(ProjectItemGroupTaskItemInstance originalItem, Expander`2 expander, ISet`1 keepMetadata, ISet`1 removeMetadata)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.BackEnd.TaskBuilder.ExecuteIntrinsicTask(ItemBucket bucket)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.BackEnd.TaskBuilder.ExecuteBucket(TaskHost taskHost, ItemBucket bucket, TaskExecutionMode howToExecuteTask, Dictionary`2 lookupHash)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.BackEnd.ItemGroupIntrinsicTask.ExecuteAdd(ProjectItemGroupTaskItemInstance child, ItemBucket bucket, ISet`1 keepMetadata, ISet`1 removeMetadata)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.BackEnd.TaskBuilder.ExecuteTask(TaskExecutionMode mode, Lookup lookup)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.BackEnd.ItemGroupIntrinsicTask.ExecuteTask(Lookup lookup)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.BackEnd.TaskBuilder.ExecuteIntrinsicTask(ItemBucket bucket)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.BackEnd.TaskBuilder.ExecuteTask(TargetLoggingContext loggingContext, BuildRequestEntry requestEntry, ITargetBuilderCallback targetBuilderCallback, ProjectTargetInstanceChild taskInstance, TaskExecutionMode mode, Lookup inferLookup, Lookup executeLookup, CancellationToken cancellationToken)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.BackEnd.TaskBuilder.ExecuteBucket(TaskHost taskHost, ItemBucket bucket, TaskExecutionMode howToExecuteTask, Dictionary`2 lookupHash)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.BackEnd.TargetEntry.ProcessBucket(ITaskBuilder taskBuilder, TargetLoggingContext targetLoggingContext, TaskExecutionMode mode, Lookup lookupForInference, Lookup lookupForExecution)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.BackEnd.TaskBuilder.ExecuteTask(TaskExecutionMode mode, Lookup lookup)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.BackEnd.TaskBuilder.ExecuteTask(TargetLoggingContext loggingContext, BuildRequestEntry requestEntry, ITargetBuilderCallback targetBuilderCallback, ProjectTargetInstanceChild taskInstance, TaskExecutionMode mode, Lookup inferLookup, Lookup executeLookup, CancellationToken cancellationToken)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.BackEnd.TargetEntry.ProcessBucket(ITaskBuilder taskBuilder, TargetLoggingContext targetLoggingContext, TaskExecutionMode mode, Lookup lookupForInference, Lookup lookupForExecution)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.BackEnd.TargetEntry.ExecuteTarget(ITaskBuilder taskBuilder, BuildRequestEntry requestEntry, ProjectLoggingContext projectLoggingContext, CancellationToken cancellationToken)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.BackEnd.TargetBuilder.ProcessTargetStack(ITaskBuilder taskBuilder)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.BackEnd.TargetEntry.ExecuteTarget(ITaskBuilder taskBuilder, BuildRequestEntry requestEntry, ProjectLoggingContext projectLoggingContext, CancellationToken cancellationToken)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.BackEnd.TargetBuilder.BuildTargets(ProjectLoggingContext loggingContext, BuildRequestEntry entry, IRequestBuilderCallback callback, String[] targetNames, Lookup baseLookup, CancellationToken cancellationToken)'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.BackEnd.TargetBuilder.ProcessTargetStack(ITaskBuilder taskBuilder)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.BackEnd.RequestBuilder.BuildProject()'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: '   at Microsoft.Build.BackEnd.RequestBuilder.BuildAndReport()'
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: post: ''
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.BackEnd.TargetBuilder.BuildTargets(ProjectLoggingContext loggingContext, BuildRequestEntry entry, IRequestBuilderCallback callback, String[] targetNames, Lookup baseLookup, CancellationToken cancellationToken)'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.BackEnd.RequestBuilder.BuildProject()'. Does not match condition '[msg == 'Started']'.
[xUnit.net 00:03:56.73]         8/11/2020 5:22:22 PM: recv: '   at Microsoft.Build.BackEnd.RequestBuilder.BuildAndReport()'. Does not match condition '[msg == 'Started']'.

console.5303f2bf.txt

About this issue

Original URL
State: closed
Created 4 years ago
Comments: 20 (20 by maintainers)

Most upvoted comments

/fyi Arcade updates will update our .NET SDK but only when we let ourselves fall behind their minimum. Right now the Arcade minimum is just before the previous public preview (5.0.100-preview.6.20310.4).

dougbu on Aug 20, 2020