IOException running NuGet-Migrations during tests in dotnet CLI first run #80619

akoeplinger · 2023-01-13T17:27:41Z

This is affecting 6.0, 7.0 and 8.0.

In #80510 (comment) we saw a failure because some NuGet migration code failed to run during the dotnet CLI first run experience:

+ dotnet /datadisks/disk1/work/ADFC09B1/p/xunit/xunit.console.dll JIT/HardwareIntrinsics/JIT.HardwareIntrinsics.XUnitWrapper.dll -parallel collections -nocolor -noshadow -xml testResults.xml -trait TestGroup=JIT.HardwareIntrinsics.Arm.ArmBase
Microsoft.DotNet.XUnitConsoleRunner v2.5.0 (64-bit .NET 7.0.2)
  Discovering: JIT.HardwareIntrinsics.XUnitWrapper (method display = ClassAndMethod, method display options = None)
  Discovered:  JIT.HardwareIntrinsics.XUnitWrapper (found 6 of 362 test cases)
  Starting:    JIT.HardwareIntrinsics.XUnitWrapper (parallel test collections = on, max threads = 2)
    JIT/HardwareIntrinsics/Arm/ArmBase.Arm64/ArmBase.Arm64_ro/ArmBase.Arm64_ro.sh [FAIL]
      System.IO.IOException: The system cannot open the device or file specified. : 'NuGet-Migrations'
         at System.Threading.Mutex.CreateMutexCore(Boolean initiallyOwned, String name, Boolean& createdNew)
         at System.Threading.Mutex..ctor(Boolean initiallyOwned, String name)
         at NuGet.Common.Migrations.MigrationRunner.Run()
         at Microsoft.DotNet.Configurer.DotnetFirstTimeUseConfigurer.Configure()
         at Microsoft.DotNet.Cli.Program.ConfigureDotNetForFirstTimeUse(IFirstTimeUseNoticeSentinel firstTimeUseNoticeSentinel, IAspNetCertificateSentinel aspNetCertificateSentinel, IFileSentinel toolPathSentinel, Boolean isDotnetBeingInvokedFromNativeInstaller, DotnetFirstRunConfiguration dotnetFirstRunConfiguration, IEnvironmentProvider environmentProvider, Dictionary`2 performanceMeasurements)
         at Microsoft.DotNet.Cli.Program.ProcessArgs(String[] args, TimeSpan startupTime, ITelemetry telemetryClient)
         at Microsoft.DotNet.Cli.Program.Main(String[] args)
      
      Return code:      1

We should look into disabling the first run experience via the DOTNET_SKIP_FIRST_TIME_EXPERIENCE=1 env var, it doesn't make sense to run that for the tests.

Report

Build	Definition	Test	Pull Request
368683	dotnet/runtime	JIT.Methodical.eE.WorkItemExecution	#90241
362596	dotnet/runtime	JIT.Methodical.eE.WorkItemExecution	#89003
361655	dotnet/runtime	JIT.Math.WorkItemExecution	#89905
361259	dotnet/runtime	JIT.Generics.WorkItemExecution
361075	dotnet/runtime	JIT.Regression.WorkItemExecution	#89867
360768	dotnet/runtime	JIT.Regression.JitBlue.WorkItemExecution	#89815
360148	dotnet/runtime	JIT.jit64.WorkItemExecution	#89814
359522	dotnet/runtime	JIT.Methodical.WorkItemExecution	#89805
356421	dotnet/runtime	JIT.Methodical.a-dA-D.WorkItemExecution
355235	dotnet/runtime	JIT.Methodical.f-iF-I.WorkItemExecution	#89009
343534	dotnet/runtime	JIT.Methodical.WorkItemExecution
342037	dotnet/runtime	JIT.Regression.JitBlue.WorkItemExecution	#89008
341937	dotnet/runtime	JIT.Methodical.a-dA-D.WorkItemExecution	#89003
337982	dotnet/runtime	JIT.HardwareIntrinsics.X86.Avx2.WorkItemExecution	#88809
337742	dotnet/runtime	JIT.Regression.CLR-x86-JIT.V1-M12-M13.WorkItemExecution	#88769

Summary

24-Hour Hit Count	7-Day Hit Count	1-Month Count
0	1	15

Known Issue Error Message

Fill the error message using known issues guidance.

{
  "ErrorPattern": "The system cannot open the device or file specified. : (&#39;|')NuGet-Migrations(&#39;|')",
  "BuildRetry": false,
  "ExcludeConsoleLog": false
}

Known issue validation

Build: 🔎
Result validation: ⚠️ Validation could not be done without an Azure DevOps build URL on the issue. Please add it to the "Build: 🔎" line.
Validation performed at: 6/28/2023 10:04:55 PM UTC

The text was updated successfully, but these errors were encountered:

ghost · 2023-01-13T17:27:46Z

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

Issue Details

In #80510 (comment) we saw a failure because some NuGet migration code failed to run during the dotnet CLI first run experience:

+ dotnet /datadisks/disk1/work/ADFC09B1/p/xunit/xunit.console.dll JIT/HardwareIntrinsics/JIT.HardwareIntrinsics.XUnitWrapper.dll -parallel collections -nocolor -noshadow -xml testResults.xml -trait TestGroup=JIT.HardwareIntrinsics.Arm.ArmBase
Microsoft.DotNet.XUnitConsoleRunner v2.5.0 (64-bit .NET 7.0.2)
  Discovering: JIT.HardwareIntrinsics.XUnitWrapper (method display = ClassAndMethod, method display options = None)
  Discovered:  JIT.HardwareIntrinsics.XUnitWrapper (found 6 of 362 test cases)
  Starting:    JIT.HardwareIntrinsics.XUnitWrapper (parallel test collections = on, max threads = 2)
    JIT/HardwareIntrinsics/Arm/ArmBase.Arm64/ArmBase.Arm64_ro/ArmBase.Arm64_ro.sh [FAIL]
      System.IO.IOException: The system cannot open the device or file specified. : 'NuGet-Migrations'
         at System.Threading.Mutex.CreateMutexCore(Boolean initiallyOwned, String name, Boolean& createdNew)
         at System.Threading.Mutex..ctor(Boolean initiallyOwned, String name)
         at NuGet.Common.Migrations.MigrationRunner.Run()
         at Microsoft.DotNet.Configurer.DotnetFirstTimeUseConfigurer.Configure()
         at Microsoft.DotNet.Cli.Program.ConfigureDotNetForFirstTimeUse(IFirstTimeUseNoticeSentinel firstTimeUseNoticeSentinel, IAspNetCertificateSentinel aspNetCertificateSentinel, IFileSentinel toolPathSentinel, Boolean isDotnetBeingInvokedFromNativeInstaller, DotnetFirstRunConfiguration dotnetFirstRunConfiguration, IEnvironmentProvider environmentProvider, Dictionary`2 performanceMeasurements)
         at Microsoft.DotNet.Cli.Program.ProcessArgs(String[] args, TimeSpan startupTime, ITelemetry telemetryClient)
         at Microsoft.DotNet.Cli.Program.Main(String[] args)
      
      Return code:      1

We should look into disabling the first run experience via the DOTNET_SKIP_FIRST_TIME_EXPERIENCE=1 env var, it doesn't make sense to run that for the tests.

Author:	akoeplinger
Assignees:	-
Labels:	`area-Infrastructure`
Milestone:	-

ViktorHofer · 2023-01-13T18:58:01Z

I thought that we were already setting that property at least for libraries tests. Maybe not for runtime tests? cc @jkoritzinsky

carlossanlop · 2023-01-13T21:00:22Z

Another PR that hit this: #80615

radical · 2023-02-07T16:23:40Z

I'm hitting this fairly often. For example on a rolling build(log).

radical · 2023-02-07T16:24:44Z

Another rolling build(log).

carlossanlop · 2023-02-09T01:39:14Z

Another 7.0 dependency flow PR affected by this: #81812

carlossanlop · 2023-02-09T01:40:50Z

I thought that we were already setting that property at least for libraries tests. Maybe not for runtime tests? cc @jkoritzinsky

Ping @jkoritzinsky

lewing · 2023-02-24T19:13:51Z

did we do something in net8 that needs to also be done in net7 here?

radical · 2023-02-28T17:21:29Z

This is affecting lot of builds.

trylek · 2023-02-28T20:28:41Z

I don't see any property / variable named DOTNET_SKIP_FIRST_TIME_EXPERIENCE in the dotnet/sdk repo, @ViktorHofer / @akoeplinger - am I looking in the wrong place (can you please point me to the place where it's used?) or are you saying we need to build this as a new feature? In fact I'm somewhat puzzled by the above code, these are apparently CoreCLR tests and they shouldn't be normally executed via dotnet, that must be coming from somewhere else like Crossgen2 execution.

radical · 2023-02-28T20:32:41Z

https://github.com/dotnet/sdk/blob/main/documentation/manpages/sdk/dotnet-environment-variables.7#L296 Was it removed?

trylek · 2023-02-28T20:34:47Z

This one is interesting but it's not the root thing, it just reacts on the fact that the variable isn't used anywhere:

dotnet/sdk@27b6661

I continue looking what gutted this behavior.

trylek · 2023-02-28T21:40:13Z

OK, so as I now understand it, the call to MigrationRunner.Run that is causing the above issue is now here:

https://github.com/dotnet/sdk/blob/fbc089ea96f0187c31e9ae176278334c8d5defc6/src/Cli/Microsoft.DotNet.Configurer/DotnetFirstTimeUseConfigurer.cs#L62

The check ShouldPrintFirstTimeUseNotice() basically calls the method Exists on the IFirstTimeUseNoticeSentinel interface. It seems to me that it should be possible to pull this off by using the

https://github.com/dotnet/sdk/blob/main/src/Cli/Microsoft.DotNet.Configurer/NoOpFirstTimeUseNoticeSentinel.cs

class for the implementation of the sentinel; this seems to be tied to the conditional block

https://github.com/dotnet/sdk/blob/b68de63954610d17b82166de586567dd244a85ca/src/Cli/dotnet/Program.cs#L183

triggered by the command-line parameter

https://github.com/dotnet/sdk/blob/12209f087e1c0256db8b08e7e7217f7526628d8b/src/Cli/dotnet/Parser.cs#L32

which leads me to

https://github.com/dotnet/sdk/blob/2c98ff1381def385256788cfcbaefb3ac32f5778/src/Cli/dotnet/commands/dotnet-internal-reportinstallsuccess/InternalReportinstallsuccessCommandParser.cs#L10

In this light I tend to believe that it might be possible to workaround this by using the internal option internal-reportinstallsuccess. I must admit I'm seeing this logic for the first time so it would be great to hear confirmation from someone familiar with this logic, actually fixing this e.g. w.r.t. Crossgen2 execution in CoreCLR tests is trivial with this background.

lewing · 2023-02-28T21:50:31Z

quite a few things expect it to work https://github.com/search?q=org%3Adotnet+DOTNET_SKIP_FIRST_TIME_EXPERIENCE&type=code

trylek · 2023-02-28T22:10:55Z

As I said, I'm not all that much familiar with this era of SDK development. To reinstate the variable, I guess it would be easiest to hack around

https://github.com/dotnet/sdk/blob/b68de63954610d17b82166de586567dd244a85ca/src/Cli/dotnet/Program.cs#L168

where we're already inspecting several environment variables. Adding an extra variable representing the "no-first-time-experience" and using it in an OR clause at line

https://github.com/dotnet/sdk/blob/b68de63954610d17b82166de586567dd244a85ca/src/Cli/dotnet/Program.cs#L180

would probably go a long way towards satisfying both behaviors. Having said that, I still maintain I'm not an SDK expert so I'd love to hear from at least one person familiar with the repo that my conclusions make some sense.

trylek · 2023-02-28T22:41:18Z

@marcpopMSFT - could you please comment on this or route this to someone familiar with the code in question?

radekdoulik · 2023-03-02T13:46:22Z

Looks similar to NuGet/Home#12159

akoeplinger · 2023-03-02T14:00:32Z

Hmm interesting, looks like DOTNET_SKIP_FIRST_TIME_EXPERIENCE was removed indeed: dotnet/sdk#9945.
Given it is referenced a lot in different places and we have the nuget migration thing during first run I'd say it might be good to bring it back.

pavelsavara · 2023-03-03T13:36:17Z

Another exhibit on #82834 Log

ericstj · 2023-04-06T19:18:29Z

Hit in #84355

lewing · 2023-04-11T03:20:32Z

hit in #84420 but pattern didn't match

See #80619

lewing · 2023-04-15T01:15:00Z

Is there a plan for fixing the underlying issue here? A mutex that fails for compatibility reasons still is a very broken mutex.

kouvel · 2023-08-10T21:27:17Z

The current plan after discussion is to revert the previous changes that made session-local mutexes user-specific, and offer user-specific mutexes as a new feature in a future release.

- A previous change that was serviced back changed session-local named mutexes to be user-specific by restricting the permissions of the session directories and files under them, and adding the sticky bit to some directoires. A compat issue arose from that change, as the session directories have the session ID in their name and session IDs can be reused between different users. The current plan that we have discussed is to revert the change and service back the revert, which also restores the intended behavior, and offer user-specific mutexes as a new feature in a future .NET that would satisfy some user scenarios in a better way. - This PR reverts the previous change (first commit) and restores one change from the previous change (second commit) to improve backward compatibility due to differences in permissions for session directories before and after the change - Fixes #80619

The 8.x release should contain dotnet/runtime#90342 which fixes dotnet/runtime#80619. I hope this will fix flaky failures like https://github.com/Unity-Technologies/ml-agents/actions/runs/8268945605/job/22623023348 of the form: ``` dotnet-format............................................................Failed - hook id: dotnet-format - exit code: 1 System.IO.IOException: The system cannot open the device or file specified. : 'NuGet-Migrations' at System.Threading.Mutex.CreateMutexCore(Boolean initiallyOwned, String name, Boolean& createdNew) at System.Threading.Mutex..ctor(Boolean initiallyOwned, String name) at NuGet.Common.Migrations.MigrationRunner.Run(String migrationsDirectory) at Microsoft.DotNet.Configurer.DotnetFirstTimeUseConfigurer.Configure() at Microsoft.DotNet.Cli.Program.ConfigureDotNetForFirstTimeUse(IFirstTimeUseNoticeSentinel firstTimeUseNoticeSentinel, IAspNetCertificateSentinel aspNetCertificateSentinel, IFileSentinel toolPathSentinel, Boolean isDotnetBeingInvokedFromNativeInstaller, DotnetFirstRunConfiguration dotnetFirstRunConfiguration, IEnvironmentProvider environmentProvider, Dictionary`2 performanceMeasurements) at Microsoft.DotNet.Cli.Program.ProcessArgs(String[] args, TimeSpan startupTime, ITelemetry telemetryClient) at Microsoft.DotNet.Cli.Program.Main(String[] args) ```

akoeplinger added the area-Infrastructure label Jan 13, 2023

ghost added the untriaged New issue has not been triaged by the area owner label Jan 13, 2023

akoeplinger removed the untriaged New issue has not been triaged by the area owner label Feb 7, 2023

akoeplinger added this to the 8.0.0 milestone Feb 7, 2023

carlossanlop added the Known Build Error Use this to report build issues in the .NET Helix tab label Feb 9, 2023

carlossanlop mentioned this issue Feb 9, 2023

[release/7.0] Update dependencies from dotnet/emsdk #81812

Merged

carlossanlop mentioned this issue Feb 9, 2023

[release/7.0] Update dependencies from dotnet/llvm-project #81424

Merged

This was referenced Feb 24, 2023

[7.0] Test failure in JIT_HardwareIntrinsics._X86_Sse2_LoadLow_ro_LoadLow_ro_._X86_Sse2_LoadLow_ro_LoadLow_ro_sh() #82633

Closed

[7.0] Test failure in JIT_HardwareIntrinsics._X86_Fma_Vector256_Fma_r_Fma_r_._X86_Fma_Vector256_Fma_r_Fma_r_sh() #82632

Closed

radical mentioned this issue Feb 28, 2023

[release/6.0] CI failure in JIT.Methodical.eh tests run in Browser wasm Release AllSubsets_Mono_RuntimeTests #81388

Closed

sbomer mentioned this issue Mar 2, 2023

Mark Microsoft.NET.ILLink as non-shipping #82905

Merged

carlossanlop mentioned this issue Apr 5, 2023

Update branding to 6.0.17 #84315

Merged

vitek-karas mentioned this issue Apr 7, 2023

Add a test for warning behavior of Requires on type with a const field #84452

Merged

hoyosjs mentioned this issue Apr 10, 2023

[release/7.0] Suppress clang-16 warnings (backport #81573) #84444

Merged

AlitzelMendez mentioned this issue Apr 11, 2023

Build Analysis: Test known issue not matching errors dotnet/arcade#13118

Closed

5 tasks

steveisok pushed a commit that referenced this issue Apr 11, 2023

Add NuGet-Migrations workaround to runtime tests too (#84129)

986bd09

See #80619

EgorBo mentioned this issue Apr 15, 2023

Eliminate bound checks for "arr[index % arr.Length]" #84231

Merged

This was referenced Apr 17, 2023

[release/6.0] Move mono.mscordbi subset off the offical build #84939

Merged

[release/7.0] Move mono.mscordbi subset off the offical build #84938

Merged

SingleAccretion mentioned this issue Apr 20, 2023

Add a test for STORE_DYN_BLK(..., IND(null), ...) #85103

Merged

lewing mentioned this issue Apr 24, 2023

[main] Update dependencies from dotnet/arcade #85247

Merged

akoeplinger mentioned this issue May 4, 2023

[release/6.0-staging] Update dependencies from xharness, arcade #85725

Merged

sbomer mentioned this issue May 4, 2023

Clean up dead code in illink targets #85741

Merged

carlossanlop mentioned this issue May 16, 2023

[manual] Merge release/7.0-staging into release/7.0 #86296

Merged

LeVladIonescu mentioned this issue May 18, 2023

[mono][aot] Enabling AOT wrappers for virtual delegates #85643

Merged

sbomer mentioned this issue May 19, 2023

Fix mapping of redeclared type parameters #86353

Merged

tannergooding mentioned this issue May 19, 2023

[release/7.0] Ensure that the shuffle zero mask copies all bits #86453

Merged

carlossanlop mentioned this issue May 26, 2023

CI: Fix running the workaround for NuGet-Migrations issue #85692

Merged

kouvel mentioned this issue Aug 10, 2023

Fix session-local named mutex compat issue #90342

Merged

ghost added the in-pr There is an active PR which will close this issue when it is merged label Aug 10, 2023

kouvel closed this as completed in #90342 Aug 11, 2023

ghost removed the in-pr There is an active PR which will close this issue when it is merged label Aug 11, 2023

ghost locked as resolved and limited conversation to collaborators Sep 11, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

IOException running NuGet-Migrations during tests in dotnet CLI first run #80619

IOException running NuGet-Migrations during tests in dotnet CLI first run #80619

akoeplinger commented Jan 13, 2023 •

edited by build-analysis bot

ghost commented Jan 13, 2023

ViktorHofer commented Jan 13, 2023

carlossanlop commented Jan 13, 2023

radical commented Feb 7, 2023

radical commented Feb 7, 2023

carlossanlop commented Feb 9, 2023

carlossanlop commented Feb 9, 2023

lewing commented Feb 24, 2023

radical commented Feb 28, 2023

trylek commented Feb 28, 2023

radical commented Feb 28, 2023

trylek commented Feb 28, 2023

trylek commented Feb 28, 2023

lewing commented Feb 28, 2023

trylek commented Feb 28, 2023

trylek commented Feb 28, 2023

radekdoulik commented Mar 2, 2023

akoeplinger commented Mar 2, 2023 •

edited

pavelsavara commented Mar 3, 2023

ericstj commented Apr 6, 2023

lewing commented Apr 11, 2023

lewing commented Apr 15, 2023 •

edited

kouvel commented Aug 10, 2023

IOException running NuGet-Migrations during tests in dotnet CLI first run #80619

IOException running NuGet-Migrations during tests in dotnet CLI first run #80619

Comments

akoeplinger commented Jan 13, 2023 • edited by build-analysis bot

Report

Summary

Known Issue Error Message

Known issue validation

ghost commented Jan 13, 2023

ViktorHofer commented Jan 13, 2023

carlossanlop commented Jan 13, 2023

radical commented Feb 7, 2023

radical commented Feb 7, 2023

carlossanlop commented Feb 9, 2023

carlossanlop commented Feb 9, 2023

lewing commented Feb 24, 2023

radical commented Feb 28, 2023

trylek commented Feb 28, 2023

radical commented Feb 28, 2023

trylek commented Feb 28, 2023

trylek commented Feb 28, 2023

lewing commented Feb 28, 2023

trylek commented Feb 28, 2023

trylek commented Feb 28, 2023

radekdoulik commented Mar 2, 2023

akoeplinger commented Mar 2, 2023 • edited

pavelsavara commented Mar 3, 2023

ericstj commented Apr 6, 2023

lewing commented Apr 11, 2023

lewing commented Apr 15, 2023 • edited

kouvel commented Aug 10, 2023

akoeplinger commented Jan 13, 2023 •

edited by build-analysis bot

akoeplinger commented Mar 2, 2023 •

edited

lewing commented Apr 15, 2023 •

edited