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.

Sign up for GitHub

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

Jump to bottom

dotnet.exe prints error messages to console when launched with empty DOTNET_MULTILEVEL_LOOKUP via start process #54073

Closed
ghost opened this issue Jun 11, 2021 · 2 comments · Fixed by #84322
Closed

dotnet.exe prints error messages to console when launched with empty DOTNET_MULTILEVEL_LOOKUP via start process #54073

ghost opened this issue Jun 11, 2021 · 2 comments · Fixed by #84322
Labels
area-Host help wanted [up-for-grabs] Good issue for external contributors
Milestone
8.0.0

Comments

@ghost
Copy link

ghost commented Jun 11, 2021 •
edited by ghost
Loading

Description

It appears dotnet.exe is printing some garbage error message text to stdout whenever it's confused by the setting of the DOTNET_MULTILEVEL_LOOKUP environment variable. I hit this under msbuild, but it's likely caused any time a managed program launches dotnet.exe and sets DOTNET_MULTILEVEL_LOOKUP to empty string in the StartInfo.EnvironmentVariables (reference dotnet/msbuild/blob/main/src/Utilities/ToolTask.cs)

The errors seem to come from dotnet.exe itself. The exact build of dotnet.exe i was using is provided below.

Repro at https://github.com/aaronla-ms/bug-repros/tree/main/repro-msbuild-envvars-exec

  1. install dotnetsdk 5.0
  2. clone https://github.com/aaronla-ms/bug-repros.git
  3. dotnet build repro-msbuild-envvars-exec

expected:
no errors logged to console

actual:
weird errors logged to console, Failed to read environment variable [DOTNET_MULTILEVEL_LOOKUP], HRESULT: 0x800700CB. Full text:

$ dotnet build
Microsoft (R) Build Engine version 16.10.1+2fd48ab73 for .NET
Copyright (C) Microsoft Corporation. All rights reserved.

  Determining projects to restore...
  All projects are up-to-date for restore.
  Failed to read environment variable [DOTNET_MULTILEVEL_LOOKUP], HRESULT: 0x0
  Failed to read environment variable [DOTNET_MULTILEVEL_LOOKUP], HRESULT: 0x800700CB
  Failed to read environment variable [DOTNET_MULTILEVEL_LOOKUP], HRESULT: 0x800700CB
  5.0.301
  repro-msbuild-envvars-exec ->

Build succeeded.
    0 Warning(s)
    0 Error(s)

Time Elapsed 00:00:01.00

Configuration

$ dotnet --info
.NET SDK (reflecting any global.json):
 Version:   5.0.301
 Commit:    ef17233f86

Runtime Environment:
 OS Name:     Windows
 OS Version:  10.0.19043
 OS Platform: Windows
 RID:         win10-x64
 Base Path:   C:\Program Files\dotnet\sdk\5.0.301\

Host (useful for support):
  Version: 6.0.0-preview.4.21253.7
  Commit:  bfd6048a60

.NET SDKs installed:
  2.1.300 [C:\Program Files\dotnet\sdk]
  2.1.514 [C:\Program Files\dotnet\sdk]
  2.1.518 [C:\Program Files\dotnet\sdk]
  2.1.524 [C:\Program Files\dotnet\sdk]
  2.1.816 [C:\Program Files\dotnet\sdk]
  3.1.410 [C:\Program Files\dotnet\sdk]
  5.0.203 [C:\Program Files\dotnet\sdk]
  5.0.204 [C:\Program Files\dotnet\sdk]
  5.0.300-preview.21258.4 [C:\Program Files\dotnet\sdk]
  5.0.301 [C:\Program Files\dotnet\sdk]
  6.0.100-preview.4.21255.9 [C:\Program Files\dotnet\sdk]

.NET runtimes installed:
  Microsoft.AspNetCore.All 2.1.0 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.18 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.22 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.28 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.App 2.1.0 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.18 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.22 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.28 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.1.15 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.1.16 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 5.0.5 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 5.0.7 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 6.0.0-preview.4.21253.5 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 2.1.0 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.18 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.22 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.28 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.1.15 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.1.16 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 5.0.5 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 5.0.7 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 6.0.0-preview.4.21253.7 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.WindowsDesktop.App 3.1.15 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 3.1.16 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 5.0.5 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 5.0.7 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 6.0.0-preview.4.21254.5 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]

To install additional .NET runtimes or SDKs:
  https://aka.ms/dotnet-download

Regression?

Uncertain.

Other information
@dotnet-issue-labeler dotnet-issue-labeler bot added area-Host untriaged New issue has not been triaged by the area owner labels Jun 11, 2021
@ghost
Copy link

ghost commented Jun 11, 2021

Tagging subscribers to this area: @vitek-karas, @agocke, @VSadov
See info in area-owners.md if you want to be subscribed.

Issue Details

Description

It appears dotnet.exe is printing some garbage error message text to stdout whenever it's confused by the setting of the DOTNET_MULTILEVEL_LOOKUP environment variable. I hit this under msbuild, but it's likely caused any time a managed program launches dotnet.exe and sets DOTNET_MULTILEVEL_LOOKUP to empty string in the StartInfo.EnvironmentVariables

The errors seem to come from dotnet.exe itself. The exact build of dotnet.exe i was using is provided below.

Repro at https://github.com/aaronla-ms/bug-repros/tree/main/repro-msbuild-envvars-exec

  1. install dotnetsdk 5.0
  2. clone https://github.com/aaronla-ms/bug-repros.git
  3. dotnet build repro-msbuild-envvars-exec

expected:
no errors logged to console

actual:
weird errors logged to console, Failed to read environment variable [DOTNET_MULTILEVEL_LOOKUP], HRESULT: 0x800700CB. Full text:

$ dotnet build
Microsoft (R) Build Engine version 16.10.1+2fd48ab73 for .NET
Copyright (C) Microsoft Corporation. All rights reserved.

  Determining projects to restore...
  All projects are up-to-date for restore.
  Failed to read environment variable [DOTNET_MULTILEVEL_LOOKUP], HRESULT: 0x0
  Failed to read environment variable [DOTNET_MULTILEVEL_LOOKUP], HRESULT: 0x800700CB
  Failed to read environment variable [DOTNET_MULTILEVEL_LOOKUP], HRESULT: 0x800700CB
  5.0.301
  repro-msbuild-envvars-exec ->

Build succeeded.
    0 Warning(s)
    0 Error(s)

Time Elapsed 00:00:01.00

Configuration

$ dotnet --info
.NET SDK (reflecting any global.json):
 Version:   5.0.301
 Commit:    ef17233f86

Runtime Environment:
 OS Name:     Windows
 OS Version:  10.0.19043
 OS Platform: Windows
 RID:         win10-x64
 Base Path:   C:\Program Files\dotnet\sdk\5.0.301\

Host (useful for support):
  Version: 6.0.0-preview.4.21253.7
  Commit:  bfd6048a60

.NET SDKs installed:
  2.1.300 [C:\Program Files\dotnet\sdk]
  2.1.514 [C:\Program Files\dotnet\sdk]
  2.1.518 [C:\Program Files\dotnet\sdk]
  2.1.524 [C:\Program Files\dotnet\sdk]
  2.1.816 [C:\Program Files\dotnet\sdk]
  3.1.410 [C:\Program Files\dotnet\sdk]
  5.0.203 [C:\Program Files\dotnet\sdk]
  5.0.204 [C:\Program Files\dotnet\sdk]
  5.0.300-preview.21258.4 [C:\Program Files\dotnet\sdk]
  5.0.301 [C:\Program Files\dotnet\sdk]
  6.0.100-preview.4.21255.9 [C:\Program Files\dotnet\sdk]

.NET runtimes installed:
  Microsoft.AspNetCore.All 2.1.0 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.18 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.22 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.28 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.App 2.1.0 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.18 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.22 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.28 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.1.15 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.1.16 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 5.0.5 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 5.0.7 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 6.0.0-preview.4.21253.5 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 2.1.0 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.18 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.22 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.28 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.1.15 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.1.16 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 5.0.5 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 5.0.7 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 6.0.0-preview.4.21253.7 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.WindowsDesktop.App 3.1.15 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 3.1.16 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 5.0.5 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 5.0.7 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 6.0.0-preview.4.21254.5 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]

To install additional .NET runtimes or SDKs:
  https://aka.ms/dotnet-download

Regression?

Uncertain.

Other information

Author: aaronla-ms
Assignees: -
Labels:

area-Host, untriaged
Milestone: -

@vitek-karas
Copy link
Member

Just for ease of access - the simplest repro (note that it's the easiest way since MSBuild is easy to run, could be done via .NET as well if necessary):

<Project Sdk="Microsoft.NET.Sdk">

  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFramework>net6.0</TargetFramework>
  </PropertyGroup>

  <Target Name="Custom" BeforeTargets="BeforeBuild">
    <Exec Command="dotnet --info" EnvironmentVariables="DOTNET_MULTILEVEL_LOOKUP=" />
  </Target>

</Project>

Create a t.csproj with the above content and run dotnet build on it. Prints out:

  Failed to read environment variable [DOTNET_MULTILEVEL_LOOKUP], HRESULT: 0x80070002
  Failed to read environment variable [DOTNET_MULTILEVEL_LOOKUP], HRESULT: 0x800700CB
  Failed to read environment variable [DOTNET_MULTILEVEL_LOOKUP], HRESULT: 0x800700CB
  .NET SDK (reflecting any global.json):
   Version:   6.0.100-preview.5.21226.1
   Commit:    db05c9234e

  Runtime Environment:
   OS Name:     Windows
   OS Version:  10.0.19043
   OS Platform: Windows
   RID:         win10-x64
   Base Path:   C:\Program Files\dotnet\sdk\6.0.100-preview.5.21226.1\
  Failed to read environment variable [DOTNET_MULTILEVEL_LOOKUP], HRESULT: 0x0
  Failed to read environment variable [DOTNET_MULTILEVEL_LOOKUP], HRESULT: 0x80070012

There are several issues with the code in the host around this:

  • It incorrectly considers empty environment variables as failures. This is because GetEnvironmentVariableW will return 0 in both cases (error or empty value). We should probably copy the logic in System.Environment.GetEnvironmentVariable
  • If it determines that GetEnvironmentVariableW actually fails it print error message into stderr. But then it ignored the error and continues as if the env. variable was not set. Host must never print to stderr or stdout unless it will fail - outputs are owned by the app if it runs.

What needs to happen:

  • Fix the logic to work correctly for empty values
  • Don't print to stderr on error getting env. variable, just trace a warning (which by default doesn't go anywhere)
  • For backward compatibility reasons, ignore failures and treat them as missing variables
  • For backward compatibility reasons treat empty value as missing variable

Note: Environment.SetEnvironmentVariable will not work to setup a repro, since when it gets empty string value it will unset the variable.
Note: What seems to work is ProcessStartInfo.EnvironmentVariables

@vitek-karas vitek-karas added this to the 7.0.0 milestone Jul 9, 2021
@vitek-karas vitek-karas removed the untriaged New issue has not been triaged by the area owner label Jul 9, 2021
@agocke agocke added this to AppModel Jul 13, 2022
@agocke agocke modified the milestones: 7.0.0, 8.0.0 Jul 25, 2022
@elinor-fung elinor-fung mentioned this issue Feb 17, 2023
Closed
@elinor-fung elinor-fung added the help wanted [up-for-grabs] Good issue for external contributors label Feb 17, 2023
@pedrobsaila pedrobsaila mentioned this issue Apr 4, 2023
Merged
@ghost ghost added the in-pr There is an active PR which will close this issue when it is merged label Apr 4, 2023
@ghost ghost removed the in-pr There is an active PR which will close this issue when it is merged label Apr 11, 2023
@ghost ghost locked as resolved and limited conversation to collaborators May 11, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
area-Host help wanted [up-for-grabs] Good issue for external contributors
Projects
AppModel
Archived in project
Milestone
8.0.0
3 participants
@agocke @vitek-karas @elinor-fung