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

Restore failure due to The process cannot access the file x because it is being used by another process on Mono #12242

Closed
ayakael opened this issue Nov 14, 2022 · 13 comments
Labels

Comments

@ayakael
Copy link

ayakael commented Nov 14, 2022

NuGet Product Used

dotnet.exe

Product Version

7.0.100

Worked before?

6.0.111

Impact

It's more difficult to complete my work

Repro Steps & Context

Description

When building runtime with mono-flavored runtime, restore often fails in CI environment with The process cannot access the file x because it is being used by another process. This affects runtime, as well as other builds (confirmed roslyn), thus specificity to runtime is that this does not occur on coreclr-flavored runtime.

This thus affects s390x and ppc64le platforms, being mono-flavored runtimes. For some reason, the error occurs more often on ppc64le. This was first reported in dotnet/runtime#77364, and it seems to relate to src/NuGet.Core/NuGet.Common/ConcurrencyUtilities.cs.

Reproduction Steps

In an Alpine Edge linux-musl-x64 environment, you can use this modified aport to reproduce bug. Following steps to reproduce:

git clone https://gitlab.alpinelinux.org/ayakael/aports -b dotnet7/mono-restore
cd  aports/testing/dotnet7-stage0
abuild deps unpack prepare build

It should eventually fail.

The aport builds a minimum set of components (runtime-mono, roslyn, sdk, aspnetcore, installer) to be able to build an SDK tar, then using that produced tarball with mono-flavored runtime it builds the whole stack again. This aport is usually used to crossbuild to other platforms, but in this case I am using it to easily reproduce the bug.

You'd likely be able to reproduce this on linux-x64 by building runtime with /p:PrimaryRuntimeFlavor=Mono and trying to build runtime with produced artifacts.

Expected behavior

Restore should occur without issue

Actual behavior

Restore fails with error.

Verbose Logs

/builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100-rtm.22519.39/NuGet.RestoreEx.targets(19,5): error : The process cannot access the file '/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-d41bfecf5090e9163aa2da251246abed9e756e53/src/runtime/artifacts/obj/System.IO.Ports' because it is being used by another process. [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-d41bfecf5090e9163aa2da251246abed9e756e53/src/runtime/Build.proj]
/builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100-rtm.22519.39/NuGet.RestoreEx.targets(19,5): error :    at System.IO.FileSystem.CreateDirectory(String fullPath, UnixFileMode unixCreateMode) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-d41bfecf5090e9163aa2da251246abed9e756e53/src/runtime/Build.proj]
/builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100-rtm.22519.39/NuGet.RestoreEx.targets(19,5): error :    at System.IO.FileSystem.CreateDirectory(String fullPath) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-d41bfecf5090e9163aa2da251246abed9e756e53/src/runtime/Build.proj]
/builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100-rtm.22519.39/NuGet.RestoreEx.targets(19,5): error :    at System.IO.Directory.CreateDirectory(String path) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-d41bfecf5090e9163aa2da251246abed9e756e53/src/runtime/Build.proj]
/builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100-rtm.22519.39/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Commands.BuildAssetsUtils.WriteFiles(IEnumerable`1 files, ILogger log) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-d41bfecf5090e9163aa2da251246abed9e756e53/src/runtime/Build.proj]
/builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100-rtm.22519.39/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Commands.RestoreResult.CommitAssetsFileAsync(LockFileFormat lockFileFormat, IRestoreResult result, ILogger log, Boolean toolCommit, CancellationToken token) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-d41bfecf5090e9163aa2da251246abed9e756e53/src/runtime/Build.proj]
/builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100-rtm.22519.39/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Commands.RestoreResult.CommitAsync(ILogger log, CancellationToken token) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-d41bfecf5090e9163aa2da251246abed9e756e53/src/runtime/Build.proj]
/builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100-rtm.22519.39/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Commands.RestoreRunner.CommitAsync(RestoreResultPair restoreResult, CancellationToken token) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-d41bfecf5090e9163aa2da251246abed9e756e53/src/runtime/Build.proj]
/builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100-rtm.22519.39/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Commands.RestoreRunner.ExecuteAndCommitAsync(RestoreSummaryRequest summaryRequest, IRestoreProgressReporter progressReporter, CancellationToken token) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-d41bfecf5090e9163aa2da251246abed9e756e53/src/runtime/Build.proj]
/builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100-rtm.22519.39/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Commands.RestoreRunner.CompleteTaskAsync(List`1 restoreTasks) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-d41bfecf5090e9163aa2da251246abed9e756e53/src/runtime/Build.proj]
/builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100-rtm.22519.39/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Commands.RestoreRunner.RunAsync(IEnumerable`1 restoreRequests, RestoreArgs restoreArgs, CancellationToken token) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-d41bfecf5090e9163aa2da251246abed9e756e53/src/runtime/Build.proj]
/builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100-rtm.22519.39/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Commands.RestoreRunner.RunAsync(RestoreArgs restoreContext, CancellationToken token) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-d41bfecf5090e9163aa2da251246abed9e756e53/src/runtime/Build.proj]
/builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100-rtm.22519.39/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Build.Tasks.BuildTasksUtility.RestoreAsync(DependencyGraphSpec dependencyGraphSpec, Boolean interactive, Boolean recursive, Boolean noCache, Boolean ignoreFailedSources, Boolean disableParallel, Boolean force, Boolean forceEvaluate, Boolean hideWarningsAndErrors, Boolean restorePC, Boolean cleanupAssetsForUnsupportedProjects, ILogger log, CancellationToken cancellationToken) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-d41bfecf5090e9163aa2da251246abed9e756e53/src/runtime/Build.proj]
/builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100-rtm.22519.39/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Build.Tasks.Console.MSBuildStaticGraphRestore.RestoreAsync(String entryProjectFilePath, IDictionary`2 globalProperties, IReadOnlyDictionary`2 options) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-d41bfecf5090e9163aa2da251246abed9e756e53/src/runtime/Build.proj]

Binary logs

runtime:
runtime.binlog.log
roslyn
dotnet7-stage0-roslyn.binlog.log

@ayakael ayakael changed the title Restore failure due to The process cannot access the file x because it is being used by another process Restore failure due to The process cannot access the file x because it is being used by another process on Mono Nov 14, 2022
@ayakael
Copy link
Author

ayakael commented Nov 14, 2022

A workaround that seems to work is setting /p:DisableParallelProcessing=true, which should've been automatically set by https://github.com/NuGet/NuGet.Client/blob/dev/src/NuGet.Clients/NuGet.CommandLine/Commands/InstallCommand.cs#L69

It is quite odd that this is not an issue on s390x with dotnet sdk 6.0.111, but with 7.0.100 it is. At least I found a workaround for those platforms, but it should be investigated why parallel processing is enabled despite that piece of code. Currently testing on full build of sdk, see if what works.

@tmds
Copy link

tmds commented Nov 14, 2022

From the stacktrace: while trying to create a directory, it looks like some syscall (mkdir?) returns EAGAIN/EWOULDBLOCK.
This is not expected.

It could be filesystem related.

You could try to patch:

int32_t SystemNative_MkDir(const char* path, int32_t mode)
{
    int32_t result;
    while ((result = mkdir(path, (mode_t)mode)) < 0 && errno == EINTR);
    return result;
}

to

int32_t SystemNative_MkDir(const char* path, int32_t mode)
{
    int32_t result;
    while ((result = mkdir(path, (mode_t)mode)) < 0 && (errno == EINTR || errno == EAGAIN));
    return result;
}

and see if that makes any difference.

@ayakael
Copy link
Author

ayakael commented Nov 14, 2022

From the stacktrace: while trying to create a directory, it looks like some syscall (mkdir?) returns EAGAIN/EWOULDBLOCK. This is not expected.

It could be filesystem related.

You could try to patch:

int32_t SystemNative_MkDir(const char* path, int32_t mode)
{
    int32_t result;
    while ((result = mkdir(path, (mode_t)mode)) < 0 && errno == EINTR);
    return result;
}

to

int32_t SystemNative_MkDir(const char* path, int32_t mode)
{
    int32_t result;
    while ((result = mkdir(path, (mode_t)mode)) < 0 && (errno == EINTR || errno == EAGAIN));
    return result;
}

and see if that makes any difference.

None it seems:

  "/builds/ayakael/aports/testing/dotnet7-stage0/src/nuget/microsoft.dotnet.arcade.sdk/7.0.0-beta.22457.4/tools/Build.proj" (default target) (1) ->
                   "/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/runtime/Build.proj" (Restore target) (3) ->
                   (Restore target) -> 
                     /builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100/NuGet.RestoreEx.targets(19,5): error : The process cannot access the file '/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/runtime/artifacts/obj/WindowsBase' because it is being used by another process. [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/runtime/Build.proj]
                   /builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100/NuGet.RestoreEx.targets(19,5): error :    at System.IO.FileSystem.CreateDirectory(String fullPath, UnixFileMode unixCreateMode) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/runtime/Build.proj]
                   /builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100/NuGet.RestoreEx.targets(19,5): error :    at System.IO.FileSystem.CreateDirectory(String fullPath) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/runtime/Build.proj]
                   /builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100/NuGet.RestoreEx.targets(19,5): error :    at System.IO.DirectoryInfo.Create() [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/runtime/Build.proj]
                   /builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100/NuGet.RestoreEx.targets(19,5): error :    at NuGet.ProjectModel.LockFileFormat.Write(String filePath, LockFile lockFile) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/runtime/Build.proj]
                   /builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Commands.RestoreResult.<>c__DisplayClass48_0.<CommitAssetsFileAsync>b__2(String outputPath) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/runtime/Build.proj]
                   /builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Common.FileUtility.Replace(Action`1 writeSourceFile, String destFilePath) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/runtime/Build.proj]
                   /builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Commands.RestoreResult.CommitAssetsFileAsync(LockFileFormat lockFileFormat, IRestoreResult result, ILogger log, Boolean toolCommit, CancellationToken token) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/runtime/Build.proj]
                   /builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Commands.RestoreResult.CommitAsync(ILogger log, CancellationToken token) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/runtime/Build.proj]
                   /builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Commands.RestoreRunner.CommitAsync(RestoreResultPair restoreResult, CancellationToken token) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/runtime/Build.proj]
                   /builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Commands.RestoreRunner.ExecuteAndCommitAsync(RestoreSummaryRequest summaryRequest, IRestoreProgressReporter progressReporter, CancellationToken token) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/runtime/Build.proj]
                   /builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Commands.RestoreRunner.CompleteTaskAsync(List`1 restoreTasks) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/runtime/Build.proj]
                   /builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Commands.RestoreRunner.RunAsync(IEnumerable`1 restoreRequests, RestoreArgs restoreArgs, CancellationToken token) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/runtime/Build.proj]
                   /builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Commands.RestoreRunner.RunAsync(RestoreArgs restoreContext, CancellationToken token) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/runtime/Build.proj]
                   /builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Build.Tasks.BuildTasksUtility.RestoreAsync(DependencyGraphSpec dependencyGraphSpec, Boolean interactive, Boolean recursive, Boolean noCache, Boolean ignoreFailedSources, Boolean disableParallel, Boolean force, Boolean forceEvaluate, Boolean hideWarningsAndErrors, Boolean restorePC, Boolean cleanupAssetsForUnsupportedProjects, ILogger log, CancellationToken cancellationToken) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/runtime/Build.proj]
                   /builds/ayakael/aports/testing/dotnet7-stage0/src/bootstrap/sdk/7.0.100/NuGet.RestoreEx.targets(19,5): error :    at NuGet.Build.Tasks.Console.MSBuildStaticGraphRestore.RestoreAsync(String entryProjectFilePath, IDictionary`2 globalProperties, IReadOnlyDictionary`2 options) [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/runtime/Build.proj

dotnet7-stage0-runtime.binlog.log
(of note, I didn't rebuild the whole SDK to test this one, I just overrode previously built SDK for ppc64le with patched dotnet-runtime-7.0.0-linux-musl-ppc64le.tar.gz)

@tmds
Copy link

tmds commented Nov 14, 2022

You patched the bootstrap SDK, right? Thanks for giving it a try.

@omajid @uweigand @janani66 have you seen this issue on any .NET 7 builds for s390x/ppc64le?

@uweigand
Copy link

I haven't seen this particular error, no.

However, if you still see this with Tom's patch applied (to the bootstrap SDK, of course), something is very weird. The error message can only occur if MkDir returns with errno set to EAGAIN/EWOULDBLOCK (which is the same numerical value). But with the patch, MkDir will never return with such an errno value, so something is weird.

@ayakael
Copy link
Author

ayakael commented Nov 14, 2022

You patched the bootstrap SDK, right? Thanks for giving it a try.

@omajid @uweigand @janani66 have you seen this issue on any .NET 7 builds for s390x/ppc64le?

Indeed I did. I'll try a full rebuild of the bootstrap SDK and come back to you. Maybe something went wrong in my patching methodology. I did this quickly in between two other tasks.

@tmds
Copy link

tmds commented Nov 14, 2022

@ayakael if you'll rebuild, can you patch SystemNative_Stat in a similar way? That is the syscall call that gets made to check if a directory already exists.

@ayakael
Copy link
Author

ayakael commented Nov 14, 2022

@ayakael if you'll rebuild, can you patch SystemNative_Stat in a similar way? That is the syscall call that gets made to check if a directory already exists.

Patching SystemNative_Stat and SystemNative_MkDir with a full rebuild unfortunately does not change the result:

                    System.IO.IOException: The process cannot access the file '/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/sdk/artifacts/.nuget/packages/microsoft.bcl.asyncinterfaces/5.0.0/lib/net461' because it is being used by another process.
                        at System.IO.FileSystem.CreateDirectory(String fullPath, UnixFileMode unixCreateMode)
                        at System.IO.FileSystem.CreateDirectory(String fullPath)
                        at System.IO.Directory.CreateDirectory(String path)
                        at NuGet.Packaging.PackageFileExtractor.ExtractPackageFile(String source, String target, Stream stream)
                        at NuGet.Packaging.PackageArchiveReader.CopyFiles(String destination, IEnumerable`1 packageFiles, ExtractPackageFileDelegate extractFile, ILogger logger, CancellationToken token)
                        at NuGet.Packaging.PackageReaderBase.CopyFilesAsync(String destination, IEnumerable`1 packageFiles, ExtractPackageFileDelegate extractFile, ILogger logger, CancellationToken cancellationToken)
                        at NuGet.Packaging.PackageExtractor.<>c__DisplayClass5_0.<<InstallFromSourceAsync>b__0>d.MoveNext()
                     --- End of stack trace from previous location ---
                        at NuGet.Common.ConcurrencyUtilities.<ExecuteWithFileLockedAsync>d__5`1[[System.Boolean, System.Private.CoreLib, Version=7.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].MoveNext()
                        at NuGet.Common.ConcurrencyUtilities.<ExecuteWithFileLockedAsync>d__5`1[[System.Boolean, System.Private.CoreLib, Version=7.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].MoveNext()
                        at NuGet.Packaging.PackageExtractor.InstallFromSourceAsync(PackageIdentity packageIdentity, IPackageDownloader packageDownloader, VersionFolderPathResolver versionFolderPathResolver, PackageExtractionContext packageExtractionContext, CancellationToken token, Guid parentId)
                        at NuGet.Commands.ProjectRestoreCommand.InstallPackageAsync(RemoteMatch installItem, NuGetv3LocalRepository userPackageFolder, PackageExtractionContext packageExtractionContext, CancellationToken token)
                        at NuGet.Commands.ProjectRestoreCommand.<>c__DisplayClass15_1.<<InstallPackagesAsync>b__4>d.MoveNext()
                     --- End of stack trace from previous location ---
                        at NuGet.Commands.ProjectRestoreCommand.InstallPackagesAsync(HashSet`1 uniquePackages, IEnumerable`1 graphs, IList`1 downloadDependencyInformations, NuGetv3LocalRepository userPackageFolder, CancellationToken token)
                        at NuGet.Commands.ProjectRestoreCommand.TryRestoreAsync(LibraryRange projectRange, IEnumerable`1 frameworkRuntimePairs, NuGetv3LocalRepository userPackageFolder, IReadOnlyList`1 fallbackPackageFolders, RemoteDependencyWalker remoteWalker, RemoteWalkContext context, Boolean forceRuntimeGraphCreation, CancellationToken token, TelemetryActivity telemetryActivity, String telemetryPrefix)
                        at NuGet.Commands.RestoreCommand.ExecuteRestoreAsync(NuGetv3LocalRepository userPackageFolder, IReadOnlyList`1 fallbackPackageFolders, RemoteWalkContext context, CancellationToken token, TelemetryActivity telemetryActivity)
                        at NuGet.Commands.RestoreCommand.ExecuteAsync(CancellationToken token)
                        at NuGet.Commands.RestoreRunner.ExecuteAsync(RestoreSummaryRequest summaryRequest, CancellationToken token)
                        at NuGet.Commands.RestoreRunner.ExecuteAndCommitAsync(RestoreSummaryRequest summaryRequest, IRestoreProgressReporter progressReporter, CancellationToken token)
                        at NuGet.Commands.RestoreRunner.CompleteTaskAsync(List`1 restoreTasks)
                        at NuGet.Commands.RestoreRunner.RunAsync(IEnumerable`1 restoreRequests, RestoreArgs restoreArgs, CancellationToken token)
                        at NuGet.Commands.RestoreRunner.RunAsync(RestoreArgs restoreContext, CancellationToken token)
                        at NuGet.Build.Tasks.BuildTasksUtility.RestoreAsync(DependencyGraphSpec dependencyGraphSpec, Boolean interactive, Boolean recursive, Boolean noCache, Boolean ignoreFailedSources, Boolean disableParallel, Boolean force, Boolean forceEvaluate, Boolean hideWarningsAndErrors, Boolean restorePC, Boolean cleanupAssetsForUnsupportedProjects, ILogger log, CancellationToken cancellationToken)

dotnet7-stage0-sdk.binlog.log

@ayakael
Copy link
Author

ayakael commented Nov 15, 2022

Well - my workaround seems to have failed me on this run, and there's no stacktrace now:

00:19:35.789 24:15>Project "/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/sdk/src/Microsoft.Win32.Msi/Microsoft.Win32.Msi.csproj" (24:15) is building "/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/sdk/src/Microsoft.Win32.Msi/Microsoft.Win32.Msi.csproj" (24:16) on node 64 (UpdateXlf target(s)).
00:19:36.809  75:2>Task "AllowEmptyTelemetry" (TaskId:26)
00:19:36.221 31:17>/builds/ayakael/aports/testing/dotnet7-stage0/src/nuget/microsoft.dotnet.xlifftasks/1.0.0-beta.22427.1/build/Microsoft.DotNet.XliffTasks.targets(46,5): error MSB3191: Unable to create directory "/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/sdk/artifacts/obj/Release/Sdks/Microsoft.NET.Sdk/tools/Release/net7.0/Microsoft.NET.Build.Tasks.xlf/". The process cannot access the file '/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/sdk/artifacts/obj/Release/Sdks/Microsoft.NET.Sdk/tools/Release/net7.0' because it is being used by another process. [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/sdk/src/Tasks/Microsoft.NET.Build.Tasks/Microsoft.NET.Build.Tasks.csproj:: TargetFramework=net7.0]
00:19:37.237 11:12>_CheckAndUnsetUnsupportedPrefer32Bit: (TargetId:68)

dotnet7-stage0-sdk.binlog.log

I'm trying now to use both the above patches + /p:RestoreParallelDisable=true and see how that goes.

(well duh cause for some reason I went from /p:DisableParallelProcessing=true to the above)
final edit I'm all kinds of stupid today, /p:RestoreParallelDisable=true should've been /p:RestoreDisableParallel=true. Now it works!

@erdembayar erdembayar added Functionality:Restore Platform:Mono NuGet.exe on mono scenarios and removed Triage:Untriaged labels Nov 15, 2022
@ayakael
Copy link
Author

ayakael commented Nov 15, 2022

Stuff gets weirder and weirder. Hopefully more data points will help triangulate this issue. Another restore-related failure when building arcade:

  [SourceBuiltSdkResolver] Looking for SDK Microsoft.NET.SDK.WorkloadManifestTargetsLocator. Detected config(s) in env: 'ARCADE' for 'Microsoft.DotNet.Arcade.Sdk/7.0.0-beta.22513.4' at '/builds/ayakael/aports/testing/dotnet7-build/src/dotnet-v7.0.100-rtm.22521.12/packages/restored/ArcadeBootstrapPackage/microsoft.dotnet.arcade.sdk/7.0.0-beta.22513.4/'
                         Determining projects to restore...
                       
                       =================================================================
                       	Native Crash Reporting
                       =================================================================
                       Got a SIGSEGV while executing native code. This usually indicates
                       a fatal error in the mono runtime or one of the native libraries 
                       used by your application.
                       =================================================================
                       
                       =================================================================
                       	Basic Fault Address Reporting
                       =================================================================
                       Memory around native instruction pointer (0x7fff85046ed8):0x7fff85046ec8  00 00 80 38 78 2b bb 7c 78 1b 7e 7c 00 00 85 90  ...8x+.|x.~|....
                       0x7fff85046ed8  20 00 9c a0 01 00 84 70 10 00 81 41 78 e3 83 7f   ......p...Ax...
                       0x7fff85046ee8  c5 7e 2d 48 18 00 41 e8 78 e3 83 7f ed 86 2d 48  .~-H..A.x.....-H
                       0x7fff85046ef8  18 00 41 e8 20 00 63 70 58 00 82 40 be ff 62 3c  ..A. .cpX..@..b<
                       
                       =================================================================
                       	Managed Stacktrace:
                       =================================================================
                       	  at <unknown> <0xffffffff>
                       	  at System.Object:__icall_wrapper_mono_marshal_isinst_with_cache <0x000f8>
                       	  at System.Object:__isinst_with_cache <0x000d0>
                       	  at System.Linq.Enumerable:Any <0x00178>
                       	  at NuGet.Frameworks.FrameworkNameProvider:TryGetCompatibilityMappings <0x00410>
                       	  at <ExpandInternal>d__4:MoveNext <0x008e8>
                       	  at <Expand>d__3:MoveNext <0x0051c>
                       	  at System.Collections.Generic.List`1:InsertRange <0x00414>
                       	  at System.Collections.Generic.List`1:AddRange <0x0007c>
                       	  at NuGet.Frameworks.CompatibilityProvider:IsCompatibleWithTarget <0x00204>
                       	  at NuGet.Frameworks.CompatibilityProvider:IsCompatibleCore <0x0029c>
                       	  at NuGet.Frameworks.CompatibilityProvider:IsCompatible <0x001b8>
                       	  at <>c__DisplayClass7_0:<GetNearestInternal>b__3 <0x00084>
                       	  at <>c__DisplayClass1_0`1:<CombinePredicates>b__0 <0x0009c>
                       	  at WhereEnumerableIterator`1:MoveNext <0x001c4>
                       	  at System.Linq.Enumerable:Any <0x0020c>
                       	  at NuGet.Frameworks.FrameworkReducer:ReduceUpwards <0x001c4>
                       	  at NuGet.Frameworks.FrameworkReducer:GetNearestInternal <0x0072c>
                       	  at NuGet.Frameworks.FrameworkReducer:GetNearest <0x000a8>
                       	  at NuGet.Frameworks.NuGetFrameworkUtility:GetNearest <0x00228>
                       	  at NuGet.Frameworks.NuGetFrameworkUtility:GetNearest <0x00108>
                       	  at NuGet.Commands.SourceRepositoryDependencyProvider:GetDependencies <0x00228>
                       	  at <GetDependenciesCoreAsync>d__24:MoveNext <0x013e8>
                       	  at System.Runtime.CompilerServices.AsyncMethodBuilderCore:Start <0x0016c>
                       	  at NuGet.Commands.SourceRepositoryDependencyProvider:GetDependenciesCoreAsync <0x00220>
                       	  at <<GetDependenciesAsync>b__0>d:MoveNext <0x000c0>
                       	  at System.Runtime.CompilerServices.AsyncMethodBuilderCore:Start <0x0011c>
                       	  at <>c__DisplayClass23_0:<GetDependenciesAsync>b__0 <0x000e8>
                       	  at System.Lazy`1:ViaFactory <0x00108>
                       	  at System.Lazy`1:ExecutionAndPublication <0x00190>
                       	  at System.Lazy`1:CreateValue <0x001d8>
                       	  at System.Lazy`1:get_Value <0x00084>
                       	  at NuGet.Common.AsyncLazy`1:GetAwaiter <0x00084>
                       	  at <GetDependenciesAsync>d__23:MoveNext <0x008d4>
                       	  at System.Runtime.CompilerServices.AsyncMethodBuilderCore:Start <0x00144>
                       	  at NuGet.Commands.SourceRepositoryDependencyProvider:GetDependenciesAsync <0x00220>
                       	  at <CreateGraphItemAsync>d__2:MoveNext <0x001a4>
                       	  at System.Runtime.CompilerServices.AsyncMethodBuilderCore:Start <0x0013c>
                       	  at NuGet.DependencyResolver.ResolverUtility:CreateGraphItemAsync <0x001d4>
                       	  at <FindLibraryEntryAsync>d__1:MoveNext <0x00600>
                       	  at System.Runtime.CompilerServices.AsyncMethodBuilderCore:Start <0x0016c>
                       	  at NuGet.DependencyResolver.ResolverUtility:FindLibraryEntryAsync <0x001dc>
                       	  at NuGet.DependencyResolver.ResolverUtility:FindLibraryCachedAsync <0x00150>
                       	  at <CreateGraphNode>d__3:MoveNext <0x009b4>
                       	  at System.Runtime.CompilerServices.AsyncMethodBuilderCore:Start <0x00128>
                       	  at NuGet.DependencyResolver.RemoteDependencyWalker:CreateGraphNode <0x002d8>
                       	  at <CreateGraphNode>d__3:MoveNext <0x014f0>
                       	  at System.Runtime.CompilerServices.AsyncMethodBuilderCore:Start <0x00128>
                       	  at NuGet.DependencyResolver.RemoteDependencyWalker:CreateGraphNode <0x002d8>
                       	  at <WalkAsync>d__2:MoveNext <0x00328>
                       	  at System.Runtime.CompilerServices.AsyncMethodBuilderCore:Start <0x00164>
                       	  at NuGet.DependencyResolver.RemoteDependencyWalker:WalkAsync <0x00218>
                       	  at <WalkDependenciesAsync>d__13:MoveNext <0x00274>
                       	  at System.Runtime.CompilerServices.AsyncMethodBuilderCore:Start <0x0017c>
                       	  at NuGet.Commands.ProjectRestoreCommand:WalkDependenciesAsync <0x002a8>
                       	  at NuGet.Commands.ProjectRestoreCommand:WalkDependenciesAsync <0x000ac>
                       	  at <TryRestoreAsync>d__9:MoveNext <0x007f0>
                       	  at System.Runtime.CompilerServices.AsyncMethodBuilderCore:Start <0x00128>
                       	  at NuGet.Commands.ProjectRestoreCommand:TryRestoreAsync <0x0034c>
                       	  at <ExecuteRestoreAsync>d__62:MoveNext <0x00d7c>
                       	  at System.Runtime.CompilerServices.AsyncMethodBuilderCore:Start <0x00128>
                       	  at NuGet.Commands.RestoreCommand:ExecuteRestoreAsync <0x00220>
                       	  at <ExecuteAsync>d__45:MoveNext <0x02ad4>
                       	  at System.Runtime.CompilerServices.AsyncMethodBuilderCore:Start <0x00128>
                       	  at NuGet.Commands.RestoreCommand:ExecuteAsync <0x00114>
                       	  at <ExecuteAsync>d__7:MoveNext <0x001f8>
                       	  at System.Runtime.CompilerServices.AsyncMethodBuilderCore:Start <0x00124>
                       	  at NuGet.Commands.RestoreRunner:ExecuteAsync <0x00100>
                       	  at <ExecuteAndCommitAsync>d__6:MoveNext <0x000ec>
                       	  at System.Runtime.CompilerServices.AsyncMethodBuilderCore:Start <0x00144>
                       	  at NuGet.Commands.RestoreRunner:ExecuteAndCommitAsync <0x00154>
                       	  at <>c__DisplayClass2_1:<RunAsync>b__0 <0x00094>
                       	  at System.Threading.Tasks.Task`1:InnerInvoke <0x000d8>
                       	  at <>c:<.cctor>b__273_0 <0x00064>
                       	  at System.Threading.ExecutionContext:RunFromThreadPoolDispatchLoop <0x000e0>
                       	  at System.Threading.Tasks.Task:ExecuteWithThreadLocal <0x00494>
                       	  at System.Threading.Tasks.Task:ExecuteEntryUnsafe <0x00144>
                       	  at System.Threading.Tasks.Task:ExecuteFromThreadPool <0x00074>
                       	  at System.Threading.ThreadPoolWorkQueue:Dispatch <0x00668>
                       	  at WorkerThread:WorkerThreadStart <0x002dc>
                       	  at System.Threading.Thread:StartCallback <0x00170>
                       	  at System.Object:runtime_invoke_void__this__ <0x00110>
                       =================================================================
                       Aborted (core dumped)

Build_1115041952.binlog.log

This might be another musl-specific bug if threading is involved and the bug isn't reproducible on glibc. The regressive nature of this puzzles me.

@ayakael
Copy link
Author

ayakael commented Nov 15, 2022

I gave up on ppc64le for now. The workaround with setting /p:RestoreDisableParallel=true /p:DisableParallelProcessing=true stabilizes the build on s390x. ppc64le is more unstable. Keeps failing here:

                     Copying file from "/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/sdk/artifacts/bin/redist/Release/net7.0/zh-Hant/System.CommandLine.resources.dll" to "/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/sdk/artifacts/bin/redist/Release/layouts/dotnet-toolset-langpack/zh-Hant/System.CommandLine.resources.dll". (TaskId:292)
21:03:08.323  31:6>/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/sdk/src/Layout/redist/targets/GenerateLayout.targets(472,5): error MSB3026: Could not copy "/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/sdk/artifacts/bin/redist/Release/net7.0/Sdks/Microsoft.NET.Sdk/tools/net472/de/Microsoft.Deployment.DotNet.Releases.resources.dll" to "/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/sdk/artifacts/bin/redist/Release/layouts/dotnet-toolset-langpack/Sdks/Microsoft.NET.Sdk/tools/net472/de/Microsoft.Deployment.DotNet.Releases.resources.dll". Beginning retry 1 in 1000ms. The process cannot access the file '/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/sdk/artifacts/bin/redist/Release/layouts/dotnet-toolset-langpack/Sdks/Microsoft.NET.Sdk/tools' because it is being used by another process.  [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/sdk/src/Layout/redist/redist.csproj]
21:03:08.323  31:6>/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/sdk/src/Layout/redist/targets/GenerateLayout.targets(472,5): error MSB3026: Could not copy "/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/sdk/artifacts/bin/redist/Release/net7.0/Sdks/Microsoft.NET.Sdk/tools/net472/de/Microsoft.Deployment.DotNet.Releases.resources.dll" to "/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/sdk/artifacts/bin/redist/Release/layouts/dotnet-toolset-langpack/Sdks/Microsoft.NET.Sdk/tools/net472/de/Microsoft.Deployment.DotNet.Releases.resources.dll". Beginning retry 1 in 1000ms. The process cannot access the file '/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/sdk/artifacts/bin/redist/Release/layouts/dotnet-toolset-langpack/Sdks/Microsoft.NET.Sdk/tools' because it is being used by another process.  [/builds/ayakael/aports/testing/dotnet7-stage0/src/dotnet-v7.0.100-rtm.22521.12/src/sdk/src/Layout/redist/redist.csproj]
21:02:43.462   102>Restore: (TargetId:71)

dotnet7-stage0-sdk.binlog.log

edit Nevermind, s390x still unstable. There's no going around this.

@zivkan
Copy link
Member

zivkan commented Nov 16, 2022

There's a lot going on in this thread, and just skimming over the thread I don't follow everything, but I feel like this points to a bug in the mono runtime.

The docs for Directory.CreateDirectory doesn't mention any exceptions for "directory already exists". Sure enough, testing on .NET Framework (obviously on Windows), and Core CLR on Windows and Linux (well, WSL2), no exceptions are thrown.

Corelib's FileSystem.CreateDirectory ignores when Interop.Sys.MkDir returns EEXIST: https://github.com/dotnet/runtime/blob/ce5891530ed1504f766360d5fbc7ed07ee557cb8/src/libraries/System.Private.CoreLib/src/System/IO/FileSystem.Unix.cs#L294

Doesn't this imply that Mono is doing something different than CoreCLR, and has behaviour not defined in the docs, so is where the bug is?

I feel like the bug report in dotnet/runtime would be more appropriate than here in NuGet/Home.

@ayakael
Copy link
Author

ayakael commented Nov 16, 2022

RestoreDisableParallel

Copy that, we'll move this back to runtime land. I had first thought it was runtime, but then stuff pointed towards nuget, but now it looks to be back to runtime. Thanks for the help!

@ayakael ayakael closed this as completed Nov 16, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

5 participants