Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

TaskCanceledException in msbuild while building on OSX-x64 #69190

Closed
jakobbotsch opened this issue May 11, 2022 · 16 comments
Closed

TaskCanceledException in msbuild while building on OSX-x64 #69190

jakobbotsch opened this issue May 11, 2022 · 16 comments
Labels
area-Infrastructure blocking-clean-ci Blocking PR or rolling runs of 'runtime' or 'runtime-extra-platforms'

Comments

@jakobbotsch
Copy link
Member

jakobbotsch commented May 11, 2022

Pipeline: https://dev.azure.com/dnceng/public/_build/results?buildId=1764261&view=logs&j=1f8f000c-1adc-5434-677a-95dd9e006aba
Log: https://dev.azure.com/dnceng/9ee6d478-d288-47f7-aacc-f6e6d082ae6d/_apis/build/builds/1764261/logs/187

/Users/runner/work/1/s/.dotnet/sdk/7.0.100-preview.3.22179.4/MSBuild.dll /nologo -maxcpucount /m -verbosity:m /v:minimal /bl:/Users/runner/work/1/s/artifacts/log/Checked/ToolsetRestore.binlog /clp:Summary /clp:ErrorsOnly;NoSummary /nr:false /p:TreatWarningsAsErrors=true /p:ContinuousIntegrationBuild=true /p:__ToolsetLocationOutputFile=/Users/runner/work/1/s/artifacts/toolset/7.0.0-beta.22255.2.txt /t:__WriteToolsetLocation /warnaserror /Users/runner/work/1/s/artifacts/toolset/restore.proj
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error : System.AggregateException: One or more errors occurred. (A task was canceled.)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :  ---> System.Threading.Tasks.TaskCanceledException: A task was canceled.
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at System.Threading.Tasks.Task.GetExceptions(Boolean includeTaskCanceledExceptions)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at System.Threading.Tasks.Task.ThrowIfExceptional(Boolean includeTaskCanceledExceptions)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at System.Threading.Tasks.Task`1.GetResultCore(Boolean waitCompletionNotification)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at Microsoft.Build.NuGetSdkResolver.NuGetSdkResolver.NuGetAbstraction.GetSdkResult(SdkReference sdk, Object nuGetVersion, SdkResolverContext context, SdkResultFactory factory)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at Microsoft.Build.NuGetSdkResolver.NuGetSdkResolver.Resolve(SdkReference sdkReference, SdkResolverContext resolverContext, SdkResultFactory factory)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at Microsoft.Build.BackEnd.SdkResolution.SdkResolverService.ResolveSdk(Int32 submissionId, SdkReference sdk, LoggingContext loggingContext, ElementLocation sdkReferenceLocation, String solutionPath, String projectPath, Boolean interactive, Boolean isRunningInVisualStudio)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at Microsoft.Build.BackEnd.SdkResolution.CachingSdkResolverService.<>c__DisplayClass3_0.<ResolveSdk>b__2()
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at System.Lazy`1.ViaFactory(LazyThreadSafetyMode mode)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at System.Lazy`1.ExecutionAndPublication(LazyHelper executionAndPublication, Boolean useDefaultConstructor)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at System.Lazy`1.CreateValue()
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at Microsoft.Build.BackEnd.SdkResolution.CachingSdkResolverService.ResolveSdk(Int32 submissionId, SdkReference sdk, LoggingContext loggingContext, ElementLocation sdkReferenceLocation, String solutionPath, String projectPath, Boolean interactive, Boolean isRunningInVisualStudio)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at Microsoft.Build.Evaluation.Evaluator`4.ExpandAndLoadImportsFromUnescapedImportExpressionConditioned(String directoryOfImportingFile, ProjectImportElement importElement, List`1& projects, SdkResult& sdkResult, Boolean throwOnFileNotExistsError)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at Microsoft.Build.Evaluation.Evaluator`4.ExpandAndLoadImports(String directoryOfImportingFile, ProjectImportElement importElement, SdkResult& sdkResult)

I hit this in #69180 as well (log].

Binlog: ToolsetRestore.zip

@rainersigwald any idea what this could be?

{ 
    "ErrorMessage":"at Microsoft.Build.NuGetSdkResolver.NuGetSdkResolver.NuGetAbstraction.GetSdkResult" 
}

Report

Build Definition Step Name Console log
1827271 dotnet/runtime Build product Log
1820085 dotnet/runtime Copy native test components to test output folder Log
1820032 dotnet/runtime Build Log
1820577 dotnet/runtime Build and generate native prerequisites Log
1821074 dotnet/runtime Prepare TestHost with runtime CoreCLR Log
1821605 dotnet/runtime Build product Log
1821600 dotnet/runtime Build product Log
1821562 dotnet/runtime Build product Log
1821616 dotnet/runtime Prepare TestHost with runtime CoreCLR Log
1822383 dotnet/runtime Build product Log
1822192 dotnet/runtime Copy native test components to test output folder Log
1822308 dotnet/runtime Restore and Build Product Log
1822365 dotnet/runtime Build product Log
1822196 dotnet/runtime Build Log
1822310 dotnet/runtime Build product Log
1822932 dotnet/runtime Restore and Build Product Log
1821879 dotnet/runtime Send to Helix Log
1823221 dotnet/runtime Prepare TestHost with runtime CoreCLR Log
1823854 dotnet/runtime Prepare TestHost with runtime CoreCLR Log
1824411 dotnet/runtime Build Log
1825319 dotnet/runtime Build product Log
1824903 dotnet/runtime Restore blob feed tasks (Windows) Log
1825815 dotnet/runtime Restore and Build Product Log
1825938 dotnet/runtime Build and generate native prerequisites Log
1826197 dotnet/runtime Build product Log
1826884 dotnet/runtime Build product Log
1826971 dotnet/runtime Build product Log
1783262 dotnet/runtime Restore and Build Product Log
1781810 dotnet/runtime Build product Log
1779412 dotnet/runtime Restore and Build Product Log
1779219 dotnet/runtime Prepare TestHost with runtime CoreCLR Log
1777497 dotnet/runtime Prepare TestHost with runtime CoreCLR Log
1777677 dotnet/runtime Generate AOT offsets Log
1777469 dotnet/runtime Send to Helix Log
1777014 dotnet/runtime Restore and Build Product Log
1777589 dotnet/runtime Build and generate native prerequisites Log
1777615 dotnet/runtime Build and generate native prerequisites Log
1777648 dotnet/runtime Build product Log
1777845 dotnet/runtime Build product Log
1779101 dotnet/runtime Build product Log
1779138 dotnet/runtime Build product Log
1779807 dotnet/runtime Restore and Build Product Log
1779730 dotnet/runtime Generate AOT offsets Log
1780676 dotnet/runtime Build and generate native prerequisites Log
1781646 dotnet/runtime Build product Log
1818438 dotnet/runtime Build product Log
1818251 dotnet/runtime Build product Log
1814750 dotnet/runtime Build and generate native prerequisites Log
1812402 dotnet/runtime Prepare TestHost with runtime Mono Log
1810652 dotnet/runtime Restore and Build Product Log
1810184 dotnet/runtime Build product Log
1809389 dotnet/runtime Build product Log
1808062 dotnet/runtime Prepare TestHost with runtime CoreCLR Log
1808917 dotnet/runtime Restore and Build Product Log
1811848 dotnet/runtime Build product Log
1812109 dotnet/runtime Build and generate native prerequisites Log
1812424 dotnet/runtime Build product Log
1812579 dotnet/runtime Build product Log
1812857 dotnet/runtime Build product Log
1814339 dotnet/runtime Build and generate native prerequisites Log
1814515 dotnet/runtime Restore and Build Product Log
1814857 dotnet/runtime Prepare TestHost with runtime CoreCLR Log
1815062 dotnet/runtime Build product Log
1815071 dotnet/runtime Build product Log
1816080 dotnet/runtime Restore and Build Product Log
1817169 dotnet/runtime Copy native test components to test output folder Log
1817345 dotnet/runtime Build and generate native prerequisites Log
1817617 dotnet/runtime Build product Log
1806666 dotnet/runtime Prepare TestHost with runtime CoreCLR Log
1805214 dotnet/runtime Build product Log
1803431 dotnet/runtime Build and generate native prerequisites Log
1801769 dotnet/runtime Build product Log
1798670 dotnet/runtime Build CoreHost Log
1797464 dotnet/runtime Restore and Build Product Log
1796182 dotnet/runtime Build CoreHost Log
1796730 dotnet/runtime Restore and Build Product Log
1796716 dotnet/runtime Build product Log
1796713 dotnet/runtime Build Log
1798210 dotnet/runtime Copy native test components to test output folder Log
1798636 dotnet/runtime Build product Log
1799893 dotnet/runtime Build product Log
1801469 dotnet/runtime Build CoreHost Log
1801768 dotnet/runtime Build CoreHost Log
1801951 dotnet/runtime Generate AOT offsets Log
1801896 dotnet/runtime Build product Log
1802758 dotnet/runtime Build product Log
1802459 dotnet/runtime Build product Log
1802562 dotnet/runtime Prepare TestHost with runtime CoreCLR Log
1802578 dotnet/runtime Copy native test components to test output folder Log
1802701 dotnet/runtime Build product Log
1802984 dotnet/runtime Copy native test components to test output folder Log
1803018 dotnet/runtime Restore and Build Product Log
1803167 dotnet/runtime Restore and Build Product Log
1803407 dotnet/runtime Build product Log
1804328 dotnet/runtime Build and generate native prerequisites Log
1806698 dotnet/runtime Build and generate native prerequisites Log
1806708 dotnet/runtime Build product Log
1792541 dotnet/runtime Build and generate native prerequisites Log
1790340 dotnet/runtime Prepare TestHost with runtime CoreCLR Log
1788726 dotnet/runtime Build Log
Displaying 100 of 124 results

Summary

24-Hour Hit Count 7-Day Hit Count 1-Month Count
0 32 124
@dotnet-issue-labeler
Copy link

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

@jakobbotsch jakobbotsch added area-Infrastructure blocking-clean-ci Blocking PR or rolling runs of 'runtime' or 'runtime-extra-platforms' labels May 11, 2022
@rainersigwald
Copy link
Member

@jeffkl Seen this apparent NuGet SDK resolver cancellation?

@ghost ghost added the untriaged New issue has not been triaged by the area owner label May 11, 2022
@ghost
Copy link

ghost commented May 11, 2022

Tagging subscribers to this area: @dotnet/runtime-infrastructure
See info in area-owners.md if you want to be subscribed.

Issue Details

Pipeline: https://dev.azure.com/dnceng/public/_build/results?buildId=1764261&view=logs&j=1f8f000c-1adc-5434-677a-95dd9e006aba
Log: https://dev.azure.com/dnceng/9ee6d478-d288-47f7-aacc-f6e6d082ae6d/_apis/build/builds/1764261/logs/187

/Users/runner/work/1/s/.dotnet/sdk/7.0.100-preview.3.22179.4/MSBuild.dll /nologo -maxcpucount /m -verbosity:m /v:minimal /bl:/Users/runner/work/1/s/artifacts/log/Checked/ToolsetRestore.binlog /clp:Summary /clp:ErrorsOnly;NoSummary /nr:false /p:TreatWarningsAsErrors=true /p:ContinuousIntegrationBuild=true /p:__ToolsetLocationOutputFile=/Users/runner/work/1/s/artifacts/toolset/7.0.0-beta.22255.2.txt /t:__WriteToolsetLocation /warnaserror /Users/runner/work/1/s/artifacts/toolset/restore.proj
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error : System.AggregateException: One or more errors occurred. (A task was canceled.)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :  ---> System.Threading.Tasks.TaskCanceledException: A task was canceled.
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at System.Threading.Tasks.Task.GetExceptions(Boolean includeTaskCanceledExceptions)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at System.Threading.Tasks.Task.ThrowIfExceptional(Boolean includeTaskCanceledExceptions)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at System.Threading.Tasks.Task`1.GetResultCore(Boolean waitCompletionNotification)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at Microsoft.Build.NuGetSdkResolver.NuGetSdkResolver.NuGetAbstraction.GetSdkResult(SdkReference sdk, Object nuGetVersion, SdkResolverContext context, SdkResultFactory factory)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at Microsoft.Build.NuGetSdkResolver.NuGetSdkResolver.Resolve(SdkReference sdkReference, SdkResolverContext resolverContext, SdkResultFactory factory)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at Microsoft.Build.BackEnd.SdkResolution.SdkResolverService.ResolveSdk(Int32 submissionId, SdkReference sdk, LoggingContext loggingContext, ElementLocation sdkReferenceLocation, String solutionPath, String projectPath, Boolean interactive, Boolean isRunningInVisualStudio)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at Microsoft.Build.BackEnd.SdkResolution.CachingSdkResolverService.<>c__DisplayClass3_0.<ResolveSdk>b__2()
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at System.Lazy`1.ViaFactory(LazyThreadSafetyMode mode)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at System.Lazy`1.ExecutionAndPublication(LazyHelper executionAndPublication, Boolean useDefaultConstructor)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at System.Lazy`1.CreateValue()
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at Microsoft.Build.BackEnd.SdkResolution.CachingSdkResolverService.ResolveSdk(Int32 submissionId, SdkReference sdk, LoggingContext loggingContext, ElementLocation sdkReferenceLocation, String solutionPath, String projectPath, Boolean interactive, Boolean isRunningInVisualStudio)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at Microsoft.Build.Evaluation.Evaluator`4.ExpandAndLoadImportsFromUnescapedImportExpressionConditioned(String directoryOfImportingFile, ProjectImportElement importElement, List`1& projects, SdkResult& sdkResult, Boolean throwOnFileNotExistsError)
/Users/runner/work/1/s/artifacts/toolset/restore.proj : error :    at Microsoft.Build.Evaluation.Evaluator`4.ExpandAndLoadImports(String directoryOfImportingFile, ProjectImportElement importElement, SdkResult& sdkResult)

I hit this in #69180 as well (log].

@rainersigwald any idea what this could be?

Author: jakobbotsch
Assignees: -
Labels:

area-Infrastructure

Milestone: -

@jeffkl
Copy link

jeffkl commented May 11, 2022

@rainersigwald I haven't seen that before. This part of the code hasn't changed in a long time. Since its run in a constructor, it can't really use async tasks and doesn't pass around a cancellation token. I wonder if the auth provider is involved and is timing out? Does this build use authenticated feeds?

@jakobbotsch
Copy link
Member Author

Does this build use authenticated feeds?

No, I believe this only uses public feeds without any auth.

@jeffkl
Copy link

jeffkl commented May 11, 2022

Okay so no auth, this code path still does a lot of work restoring a package by connecting to the feed to get the versions, downloading the package, and unzipping it. I suppose it could be an intermittent issue with the feed.

What is the impact of this? Is it happening a lot?

I've been working on major improvements to the NuGet SDK resolver and adding logging which will help diagnosability.

NuGet/Home#11441

@jakobbotsch
Copy link
Member Author

So far I have seen this in just a couple of builds, but I will keep an eye out. Hopefully this is just some transient issue with our feeds.

@jeffkl
Copy link

jeffkl commented May 11, 2022

@jakobbotsch sounds good, very sorry for the failure. Please keep me in the loop if you keep seeing it. I'll continue working on improving the resolver in the meantime!

@jakobbotsch
Copy link
Member Author

Another instance in https://dev.azure.com/dnceng/public/_build/results?buildId=1765596&view=results in Build iOS arm64 Release AllSubsets_Mono

@CarnaViire
Copy link
Member

This might be related to/fixed by NuGet/NuGet.Client#4596 but maybe it's hit in some other code path as well? (But from BCL point of view, that was also patched in #68649)

@jakobbotsch
Copy link
Member Author

This might be related to/fixed by NuGet/NuGet.Client#4596 but maybe it's hit in some other code path as well? (But from BCL point of view, that was also patched in #68649)

Good guess. These issues are being hit during build which is using preview3, so in that case this should resolve once a new SDK propagates.

@ViktorHofer
Copy link
Member

ViktorHofer commented May 16, 2022

dotnet/sdk#25449

Which will happen in 2-3 weeks as part of the next infrastructure rollout :) I'm already testing the ingestion of the P4 SDK to find issues early.

@danmoseley
Copy link
Member

@ViktorHofer when is the infrastructure rollout that would bring the fix above?

@ViktorHofer
Copy link
Member

cc @agocke who is driving the SDK upgrade this month. Andy, everything should be ready by now, right? We would need to send out a mail to the runtimerepo alias and open a GH issue and pin it, for internal and external communication.

@agocke
Copy link
Member

agocke commented Jun 15, 2022

Finishing up testing now: #70117

When that's done we can send the email out, pin the issue, and merge.

@agocke
Copy link
Member

agocke commented Jun 17, 2022

Preview 5 SDK update has been merged

@agocke agocke closed this as completed Jun 17, 2022
@ghost ghost removed the untriaged New issue has not been triaged by the area owner label Jun 17, 2022
@ghost ghost locked as resolved and limited conversation to collaborators Jul 17, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
area-Infrastructure blocking-clean-ci Blocking PR or rolling runs of 'runtime' or 'runtime-extra-platforms'
Projects
None yet
Development

No branches or pull requests

8 participants