search

SCons / scons

SCons - a software construction tool
http://scons.org
MIT License
2.09k stars 315 forks source link

Build as administrator is required on windows (sometimes?) #4440

Open koubaa opened 12 months ago

koubaa commented 12 months ago

Describe the bug I set up a scons-based build system at my organization. Some users have complained to me that they can only run the build as administrator. I am not able to reproduce that problem myself. Here is the error message that the users who are affected get when they build as a non-admin.

cl : Command line error D8050 : cannot execute 'C:\Program Files (x86)\Microsoft Visual Studio\2019\Professional\VC\Tools\MSVC\14.20.27508\bin\HostX64\x64\c1xx.dll': failed to get command line into debug records scons: building terminated because of errors.

I can try to get a minimal reproducible example, but apparently any c++ scons build is affected for these users. We use Visual Studio 2019

scons is invoked from python in a virtual environment where scons is installed as a subprocess. The executable in the subprocess is determined using the result of the subprocess where scons.

mwichmann commented 12 months ago

Well, the error is a compiler error, not an SCons error - SCons has found and executed a compiler binary. It seems it's trying to create a file somewhere that it hasn't the rights to, which is why running with admin rights helps. I'd be looking at the settings of environment variables TEMP and TMP in the places where this is causing trouble to see if there are any clues there. SCons does fetch those from the environment (os.environ) and put them into the execution environment so they'll be available to the processes that are kicked off by SCons.

There are other ways to specify the version you want to use, though those have evolved somewhat since 4.0, so you shouldn't have to resort to your own call to vswhere (scons is going to do that anyway) but that's not the problem since you've shown it's finding it already, since 14.2x is the 2019 series.

scons is invoked from python in a virtual environment where scons is installed as a subprocess. The executable in the subprocess is determined using the result of the subprocess where scons.

Out of curiosity, why make it so complicated?

@jcbrill any thoughts here?

koubaa commented 12 months ago

Out of curiosity, why make it so complicated?

@mwichmann I set it up to just run scons from the shell in the appropriate python environment. At some point I took on other responsibilities and someone else made that change, and I don't know why, unfortunately. But I am still asked for help by users when the build system doesn't work since I created it initially.

jcbrill commented 12 months ago

Not much to add yet.

This thread seems to be similar: https://developercommunity.visualstudio.com/t/binhostx86x86c1xxdll/314749 (emphasis added)

In my case I was running cl.exe via SCons. Scons strips the environment! So you need to tell Scons to pass through TMP from up-level environment, or just set it to something in the sconscipt.

To verify that this indeed is the case, create cl.bat somewhere in path with content that conststs of "set". This will print the environment variables. In my case TMP wasn't set to anything (and apparently cl.exe defaults to %systemroot% and fails with access denied -- that's why one of the solutions is to have cl run as admin)

At present, it sounds like a Windows environment issue.

In addition to checking that the TEMP and TMP environment variables are defined and point to folders that exist, one user experienced this error with VS2017 when the USERPROFILE environment variable was not defined.

https://stackoverflow.com/questions/52152923/vs2017-build-returns-d8050-failed-to-get-command-line-into-debug-records https://stackoverflow.com/questions/26547214/cl-exe-returing-error-code-d8050

mwichmann commented 12 months ago

SCons made this change:

  • The %TEMP% and %TMP% external environment variables are now propagated automatically to the command execution environment on Windows systems.

way back in

RELEASE 0.96.90 - Tue, 15 Feb 2005

The change to automatically propagate %USERPROFILE% into the execution environment came much later, in 2021 (more than a year after 4.0), so it's possible that is a part of the issue you're seeing.

jcbrill commented 12 months ago

USERPROFILE does not appear to be imported from the environment until version 4.4.0.

mwichmann commented 12 months ago

USERPROFILE does not appear to be imported from the environment until version 4.4.0.

Yes, I think it missed the 4.3.0 release by a couple of weeks. 

diff --git a/SCons/Platform/win32.py b/SCons/Platform/win32.py
index eeb2abff4..990794f96 100644
--- a/SCons/Platform/win32.py
+++ b/SCons/Platform/win32.py
@@ -381,7 +381,7 @@ def generate(env):
     # for SystemDrive because it's related.
     #
     # Weigh the impact carefully before adding other variables to this list.
-    import_env = ['SystemDrive', 'SystemRoot', 'TEMP', 'TMP' ]
+    import_env = ['SystemDrive', 'SystemRoot', 'TEMP', 'TMP', 'USERPROFILE']
     for var in import_env:
         v = os.environ.get(var)
         if v:
jcbrill commented 12 months ago

Typical TEMP and TMP User Variables definitions are:

TEMP=%USERPROFILE%\AppData\Local\Temp TMP=%USERPROFILE%\AppData\Local\Temp

Typical TEMP and TMP System Variables definitions are:

TEMP=%SystemRoot%\TEMP TMP=%SystemRoot%\TEMP

If the User Variable TEMP and TMP definitions are missing, there might be a permissions problem with the temp folder off the system root (as mentioned in the linked posts) which would explain why it works with admin privileges.

bdbaddog commented 12 months ago

Try upgrading to latest SCons...

jcbrill commented 12 months ago

The windows environment issue experienced is reproducible when both TEMP and TMP are undefined using scons 4.0.1 and VS2019.

If either TEMP or TMP are defined and point to a valid folder the build will succeed. USERPROFILE does not matter.

FAILS from a "normal" windows command-line prompt without TEMP and TMP:

K:\SCons\test-scons-4440>set TEMP=
K:\SCons\test-scons-4440>set TMP=
K:\SCons\test-scons-4440>set USERPROFILE=

K:\SCons\test-scons-4440>%PYEXE% ../scons-4.0.1/scripts/scons.py
scons: Reading SConscript files ...

Computer Name: VS64-DEV-W11
SCons Root: Unknown
Installed Versions: ['14.2', '14.1', '14.0', '12.0', '11.0', '10.0', '9.0', '8.0', '7.1', '7.0', '6.0']
Default Tools: ['default', 'mslink', 'msvc', 'gfortran', 'masm', 'mslib', 'dmd', 'msvs', 'midl', 'filesystem', 'jar', 'javac', 'rmic', 'tar', 'zip', 'textfile']

Build: _build-vs64-dev-w11-0001 {'MSVC_VERSION': '14.2', 'MSVC_USE_SCRIPT': 'C:\\Program Files (x86)\\Microsoft Visual Studio\\2019\\Community\\VC\\Auxiliary\\Build\\vcvars64.bat'}

scons: done reading SConscript files.
scons: Building targets ...
cl /Fo_build-vs64-dev-w11-0001\hello.obj /c src\hello.cpp /TP /MDd /EHsc /ZI /FS
Microsoft (R) C/C++ Optimizing Compiler Version 19.29.30151 for x64
Copyright (C) Microsoft Corporation.  All rights reserved.

hello.cpp
cl : Command line error D8050 : cannot execute 'C:\Program Files (x86)\Microsoft Visual Studio\2019\Community\VC\Tools\MSVC\14.29.30133\bin\HostX64\x64\c1xx.dll': failed to get command line into debug records
scons: *** [_build-vs64-dev-w11-0001\hello.obj] Error 2
scons: building terminated because of errors.

K:\SCons\test-scons-4440>

PASSES from an admin windows command prompt without TEMP and TMP:

J:\SCons\test-scons-4440>set TEMP=
J:\SCons\test-scons-4440>set TMP=
J:\SCons\test-scons-4440>set USERPROFILE=

J:\SCons\test-scons-4440>%PYEXE% ../scons-4.0.1/scripts/scons.py
scons: Reading SConscript files ...

Computer Name: VS64-DEV-W11
SCons Root: Unknown
Installed Versions: ['14.2', '14.1', '14.0', '12.0', '11.0', '10.0', '9.0', '8.0', '7.1', '7.0', '6.0']
Default Tools: ['default', 'mslink', 'msvc', 'gfortran', 'masm', 'mslib', 'dmd', 'msvs', 'midl', 'filesystem', 'jar', 'javac', 'rmic', 'tar', 'zip', 'textfile']

Build: _build-vs64-dev-w11-0001 {'MSVC_VERSION': '14.2', 'MSVC_USE_SCRIPT': 'C:\\Program Files (x86)\\Microsoft Visual Studio\\2019\\Community\\VC\\Auxiliary\\Build\\vcvars64.bat'}

scons: done reading SConscript files.
scons: Building targets ...
cl /Fo_build-vs64-dev-w11-0001\hello.obj /c src\hello.cpp /TP /MDd /EHsc /ZI /FS
Microsoft (R) C/C++ Optimizing Compiler Version 19.29.30151 for x64
Copyright (C) Microsoft Corporation.  All rights reserved.

hello.cpp

<...REMOVED...>

link /DEBUG /OUT:_build-vs64-dev-w11-0001\hello.exe kernel32.lib user32.lib _build-vs64-dev-w11-0001\hello.obj _build-vs64-dev-w11-0001\hello01.obj _build-vs64-dev-w11-0001\hello02.obj _build-vs64-dev-w11-0001\hello03.obj _build-vs64-dev-w11-0001\hello04.obj _build-vs64-dev-w11-0001\hello05.obj _build-vs64-dev-w11-0001\hello06.obj _build-vs64-dev-w11-0001\hello07.obj _build-vs64-dev-w11-0001\hello08.obj _build-vs64-dev-w11-0001\hello09.obj _build-vs64-dev-w11-0001\hello10.obj _build-vs64-dev-w11-0001\hello11.obj _build-vs64-dev-w11-0001\hello12.obj _build-vs64-dev-w11-0001\hello13.obj _build-vs64-dev-w11-0001\hello14.obj _build-vs64-dev-w11-0001\hello15.obj _build-vs64-dev-w11-0001\hello16.obj _build-vs64-dev-w11-0001\hello17.obj _build-vs64-dev-w11-0001\hello18.obj _build-vs64-dev-w11-0001\hello19.obj _build-vs64-dev-w11-0001\hello20.obj
Microsoft (R) Incremental Linker Version 14.29.30151.0
Copyright (C) Microsoft Corporation.  All rights reserved.

scons: done building targets.

J:\SCons\test-scons-4440>

PASSES from a "normal" command-line prompt with either TEMP or TMP:

K:\SCons\test-scons-4440>set TMP=
K:\SCons\test-scons-4440>set TEMP=%SYSTEMROOT%\temp
K:\SCons\test-scons-4440>set USERPROFILE=

K:\SCons\test-scons-4440>%PYEXE% ../scons-4.0.1/scripts/scons.py
scons: Reading SConscript files ...

Computer Name: VS64-DEV-W11
SCons Root: Unknown
Installed Versions: ['14.2', '14.1', '14.0', '12.0', '11.0', '10.0', '9.0', '8.0', '7.1', '7.0', '6.0']
Default Tools: ['default', 'mslink', 'msvc', 'gfortran', 'masm', 'mslib', 'dmd', 'msvs', 'midl', 'filesystem', 'jar', 'javac', 'rmic', 'tar', 'zip', 'textfile']

Build: _build-vs64-dev-w11-0001 {'MSVC_VERSION': '14.2', 'MSVC_USE_SCRIPT': 'C:\\Program Files (x86)\\Microsoft Visual Studio\\2019\\Community\\VC\\Auxiliary\\Build\\vcvars64.bat'}

scons: done reading SConscript files.
scons: Building targets ...
cl /Fo_build-vs64-dev-w11-0001\hello.obj /c src\hello.cpp /TP /MDd /EHsc /ZI /FS
Microsoft (R) C/C++ Optimizing Compiler Version 19.29.30151 for x64
Copyright (C) Microsoft Corporation.  All rights reserved.

hello.cpp

<...REMOVED...>

link /DEBUG /OUT:_build-vs64-dev-w11-0001\hello.exe kernel32.lib user32.lib _build-vs64-dev-w11-0001\hello.obj _build-vs64-dev-w11-0001\hello01.obj _build-vs64-dev-w11-0001\hello02.obj _build-vs64-dev-w11-0001\hello03.obj _build-vs64-dev-w11-0001\hello04.obj _build-vs64-dev-w11-0001\hello05.obj _build-vs64-dev-w11-0001\hello06.obj _build-vs64-dev-w11-0001\hello07.obj _build-vs64-dev-w11-0001\hello08.obj _build-vs64-dev-w11-0001\hello09.obj _build-vs64-dev-w11-0001\hello10.obj _build-vs64-dev-w11-0001\hello11.obj _build-vs64-dev-w11-0001\hello12.obj _build-vs64-dev-w11-0001\hello13.obj _build-vs64-dev-w11-0001\hello14.obj _build-vs64-dev-w11-0001\hello15.obj _build-vs64-dev-w11-0001\hello16.obj _build-vs64-dev-w11-0001\hello17.obj _build-vs64-dev-w11-0001\hello18.obj _build-vs64-dev-w11-0001\hello19.obj _build-vs64-dev-w11-0001\hello20.obj
Microsoft (R) Incremental Linker Version 14.29.30151.0
Copyright (C) Microsoft Corporation.  All rights reserved.

scons: done building targets.

K:\SCons\test-scons-4440>

Edits:

jcbrill commented 12 months ago

Try upgrading to latest SCons...

If TEMP and TMP are both undefined, the latest SCons with VS2022 will fail in the same manner.

bdbaddog commented 12 months ago

Try upgrading to latest SCons...

If TEMP and TMP are both undefined, the latest SCons with VS2022 will fail in the same manner.

I don't see that he said those aren't defined..? Regardless 4.0.1 is old. Always try with newest SCons before reporting a defect.

mwichmann commented 12 months ago

I don't see that he said those aren't defined..?

That was us running off and speculating on possible causes, and now testing (thanks @jcbrill for confirming which case it - likely - is) based on some other instances of similar.

jcbrill commented 11 months ago

Research notes thus far based on the issue report above, search results, msvc documentation, and command-line experiments for posterity.

There appears to be a confluence of events based on the windows environment and an msvc debug build that can result in build failures:

This is not specific to SCons and can be reproduced in a windows command-line environment. The behavior experienced is exactly the same as described in the second and third items below.

Background information:

While there does not appear to be specific documentation for D8050, D8049 seems to imply the usage of the windows temp folders as a source for populating the debug records.

Test methodology for windows environment without SCons for failed build:

Procmon excerpts for a failed build:

5:15:07.3381547 PM cl.exe  8208  CreateFile  C:\Windows\{9BB928B8-7056-4D5E-B84A-DCB45C12CB49}  ACCESS DENIED  Desired Access: Generic Write, Read Attributes, ...

The attempt to create a file for writing in C:\Windows\{9BB928B8-7056-4D5E-B84A-DCB45C12CB49} fails due to access restrictions for a "normal" user which results in the build failure message:

cl : Command line error D8050 : cannot execute ... : failed to get command line into debug records

Test methodology for admin windows environment without SCons for successful build:

Procmon excerpts from a successful build:

5:16:33.1787847 PM cl.exe  7900  CreateFile  C:\Windows\{23FA6196-BD74-4313-94D3-B1C0C6920F98}  SUCCESS  Desired Access: Generic Write, Read Attributes, ..., OpenResult: Created
5:16:33.1792722 PM cl.exe  7900  WriteFile   C:\Windows\{23FA6196-BD74-4313-94D3-B1C0C6920F98}  SUCCESS  Offset: 0, Length: 852, Priority: Normal
5:16:33.1796428 PM cl.exe  7900  WriteFile   C:\Windows\{23FA6196-BD74-4313-94D3-B1C0C6920F98}  SUCCESS  Offset: 852, Length: 120
5:16:33.1797237 PM cl.exe  7900  CloseFile   C:\Windows\{23FA6196-BD74-4313-94D3-B1C0C6920F98}  SUCCESS 
...
5:16:33.2503249 PM mspdbsrv.exe  692  Process Start  SUCCESS
Parent PID: 7900,
Command line: mspdbsrv.exe -start -spawn,
Current directory: C:\Program Files\Microsoft Visual Studio\2022\Community\VC\Tools\MSVC\14.37.32822\bin\HostX64\x64\,
Environment:
  ...
  ENC_CL=C:\Program Files\Microsoft Visual Studio\2022\Community\VC\Tools\MSVC\14.37.32822\bin\HostX64\x64\cl.exe
  ENC_CMD=3cb C:\WINDOWS\{23FA6196-BD74-4313-94D3-B1C0C6920F98}
  ENC_CWD=J:\SCons\test-scons-4440\src
  ENC_PDB=J:\SCons\test-scons-4440\src\vc140.pdb
  ENC_SRC=hello.cpp
  ...
...

The attempt to create a file for writing in C:\Windows\{23FA6196-BD74-4313-94D3-B1C0C6920F98} is successful and the file is populated.

The mspdbsrv.exe program is launched and includes environment variables for the temporary files (e.g., ENC_*).

The environment variable ENC_CMD is likely the command line that is referred to in the error message above.

This succeeds in an admin command interpreter due to the ability to read/write into the %SYSTEMROOT% folder.

bdbaddog commented 11 months ago

Seems like the user should FIRST try upgrading to latest SCons which we know has better MSVC logic and then we can spend any time trying to debug their issue.. We don't generally provide support to versions which are not the most current.

koubaa commented 6 months ago

@jcbrill @bdbaddog @mwichmann Sorry for the late reply here. The original user who reported the issue had issues reproducing the issue. Another user recently reported the same issue. They have %TMP%, %TEMP%, and %USERPROFILE% set and have tried SCons 4.0.1, 4.5.3, and 4.7.0 in a virtual environment. and can still reproduce the problem with all three versions of SCons.

bdbaddog commented 6 months ago

@jcbrill @bdbaddog @mwichmann Sorry for the late reply here. The original user who reported the issue had issues reproducing the issue. Another user recently reported the same issue. They have %TMP%, %TEMP%, and %USERPROFILE% set and have tried SCons 4.0.1, 4.5.3, and 4.7.0 in a virtual environment. and can still reproduce the problem with all three versions of SCons.

Are they running these from powershell or cmd.exe shell? By virtual environment, we're talking about python's venv, or virtualenv, and not something else right? Is this being run in docker, or similar?

We have seem weird issues in the past where anti-virus could impact such things.

So the original user no longer has the issue, but another user does and it's currently reproducible? How long has their machine been up? Can they try rebooting and see if it goes away?

Can you share the most minimal SConstruct which reproduces this? 

env=Environment()
env.SharedObject('hello.c', SHCXXFLAGS="$SHCXXFLAGS /MDd /EHsc /ZI /FS")

Would that do it?

jcbrill commented 6 months ago

The installed Visual Studio version number might be helpful as well (e.g., 16.1, 16.2).

Is vs2019 updated to the latest version?

jcbrill commented 6 months ago

cl : Command line error D8050 : cannot execute 'C:\Program Files (x86)\Microsoft Visual Studio\2019\Professional\VC\Tools\MSVC\14.20.27508\bin\HostX64\x64\c1xx.dll': failed to get command line into debug records scons: building terminated because of errors.

The original error message posted above in Nov 2023 shows toolset version 14.20.27508 which is a very early 2019 toolset and possibly the very first toolset.

The latest toolset version for 2019 is 14.29.30133.

Have updates to VS2019 been applied after the initial installation?

Note that the v142 tools can be used in VS2022 by using the MSVC_TOOLSET_VERSION construction variable: Environment(MSVC_VERSION='14.3', MSVC_TOOLSET_VERSION='14.2', ...)

koubaa commented 3 months ago

It took us a while but we just migrated our windows toolchain to vs2022. Some users continue to see this problem with scons 4.8.

See below: 1>cl : Command line error D8050: cannot execute 'C:\ANSYSDev\Microsoft Visual Studio\2022\Professional\VC\Tools\MSVC\14.36.32532\bin\HostX64\x64\c1xx.dll': failed to get command line into debug records

The affected user is able to build successfully when running scons from an admin command prompt.

koubaa commented 3 months ago

Are they running these from powershell or cmd.exe shell? By virtual environment, we're talking about python's venv, or virtualenv, and not something else right? Is this being run in docker, or similar?

cmd.exe (but the user can reproduce the issue in powershell), python venv, not in docker.

We have seem weird issues in the past where anti-virus could impact such things.

We can't change our antivirus settings, the windows settings are controlled by our IT

So the original user no longer has the issue, but another user does and it's currently reproducible? How long has their machine been up? Can they try rebooting and see if it goes away?

As far as I can tell the issue is reproducible across reboots and is consistently reproducible

Can you share the most minimal SConstruct which reproduces this?

env=Environment()
env.SharedObject('hello.c', SHCXXFLAGS="$SHCXXFLAGS /MDd /EHsc /ZI /FS")

Would that do it?

I would need some time but I think eventually I could produce something like that

mwichmann commented 3 months ago

We'll look at it if there's any way to.

On the antivirus topic: no idea if AV is at all involved in this problem (usually you'll get some less-than-helpful popups if so, so you'd probably know about it), but you really need to be able to whitelist a development tree, or it's going to be completely unworkable for devs. That's not anything particular to SCons. I've noticed one of the IDEs I use (the JetBrains family) detects if, once you've indicated you "trust" a project checkout, antivirus is going to be involved, it produces a program to add the whitelist settings and asks if you want to run it - so it's a widely recognized issue.

I do see some evidence on people running into this, and nobody ever comes up with a very workable solution (usually something brute-force like "uninstall and reinstall Visual Studio, so the rights get reset". Here's a quite recent instance from Microsoft's own vcpkg project, building the well-known boost C++ libraries. The build tool there is CMake (and perhaps ninja):

CMake Error at F:/src/vcpkg/downloads/tools/cmake-3.29.2-windows/cmake-3.29.2-windows-i386/share/cmake-3.29/Modules/CMakeTestCXXCompiler.cmake:60 (message):
  The C++ compiler

    "C:/Program Files/Microsoft Visual Studio/2022/Community/VC/Tools/MSVC/14.39.33519/bin/Hostx64/x64/cl.exe"

  is not able to compile a simple test program.

  It fails with the following output:

    Change Dir: 'F:/src/vcpkg/buildtrees/boost-headers/x64-windows-rel/CMakeFiles/CMakeScratch/TryCompile-swsthv'

    Run Build Command(s): "C:/Program Files/Microsoft Visual Studio/2022/Community/Common7/IDE/CommonExtensions/Microsoft/CMake/Ninja/ninja.exe" -v cmTC_2c6b6
    [1/2] C:\PROGRA~1\MICROS~3\2022\COMMUN~1\VC\Tools\MSVC\1439~1.335\bin\Hostx64\x64\cl.exe  /nologo /TP   /nologo /DWIN32 /D_WINDOWS /W3 /utf-8 /GR /EHsc /MP   /D_DEBUG /MDd /Z7 /Ob0 /Od /RTC1  -MDd /showIncludes /FoCMakeFiles\cmTC_2c6b6.dir\testCXXCompiler.cxx.obj /FdCMakeFiles\cmTC_2c6b6.dir\ /FS -c F:\src\vcpkg\buildtrees\boost-headers\x64-windows-rel\CMakeFiles\CMakeScratch\TryCompile-swsthv\testCXXCompiler.cxx
    FAILED: CMakeFiles/cmTC_2c6b6.dir/testCXXCompiler.cxx.obj 
    C:\PROGRA~1\MICROS~3\2022\COMMUN~1\VC\Tools\MSVC\1439~1.335\bin\Hostx64\x64\cl.exe  /nologo /TP   /nologo /DWIN32 /D_WINDOWS /W3 /utf-8 /GR /EHsc /MP   /D_DEBUG /MDd /Z7 /Ob0 /Od /RTC1  -MDd /showIncludes /FoCMakeFiles\cmTC_2c6b6.dir\testCXXCompiler.cxx.obj /FdCMakeFiles\cmTC_2c6b6.dir\ /FS -c F:\src\vcpkg\buildtrees\boost-headers\x64-windows-rel\CMakeFiles\CMakeScratch\TryCompile-swsthv\testCXXCompiler.cxx
    cl : Command line error D8050 : cannot execute 'C:\PROGRA~1\MICROS~3\2022\COMMUN~1\VC\Tools\MSVC\1439~1.335\bin\Hostx64\x64\c1xx.dll': failed to get command line into debug records

The issue in question is microsoft/vcpkg:38549

koubaa commented 3 months ago

Here's the command line invocation (filename & libname obscured). As a sanity check, I verified that when running as admin, it is the same command line invocation to cl:

cl /Foout\Debug\libname\fname.obj /c out\Debug\libname\fname.cc /TP /W3 /sdl- /WX- /Gd /EHsc /nologo /wd4996 /wd4267 /GS /Od /RTC1 /MDd /DNOMINMAX /DWIN32 /D_UNICODE /DUNICODE /D_DEBUG /Iout\Debug\libname /IC:\thidpartylibname\Release\include /Z7

cl : Command line error D8050 : cannot execute 'C:\ANSYSDev\Microsoft Visual Studio\2022\Professional\VC\Tools\MSVC\14.36.32532\bin\HostX64\x64\c1xx.dll': failed to get command line into debug records

bdbaddog commented 3 months ago

@koubaa - in the corporate environments I've worked in, it's sometimes possible to get IT to temporarily disable A/V to see if it's contributing to such a problem.

Did you try googling this issue? I see this answer on Stack Overflow searching for that msvc error code https://stackoverflow.com/a/30788191/82681

jcbrill commented 3 months ago

@koubaa If possible, running the attached script on the host computer might provide additional useful information about the windows environment.

Attached is scons-environ.zip which contains:

Run the attached script on the host computer in the same windows shell environment that SCons is invoked and redirect the output to a file:

After reviewing the output file content for privacy, attach the output file.

Notes:

Possible causes/resolutions from internet searches include:

The source code in its entirety:

import os
import shutil

USERPROFILE = os.environ.get("USERPROFILE", "")
USERPROFILE_NORM = USERPROFILE.lower()
SAFEPROFILE = r"Z:\USERPROFILE"
USE_SAFEPROFILE = True

_cache_drive_free = {}

MB = 1024.0 * 1024.0

def evar_path(var):
    val = os.environ.get(var, "")
    if val:
        exists = 1 if os.path.exists(val) else 0
        dollar = 1 if "$" in val else 0
        spaces = 1 if " " in val else 0
        normpath = os.path.normcase(os.path.realpath(os.path.abspath(val)))
    else:
        exists = 0
        dollar = 0
        spaces = 0
        normpath = None

    if normpath:
        drive, _ = os.path.splitdrive(normpath)
        if drive not in _cache_drive_free:
            free = shutil.disk_usage(drive).free / MB
            _cache_drive_free[drive] = free

    if USE_SAFEPROFILE and USERPROFILE and val.lower().startswith(USERPROFILE_NORM):
        safe_val = SAFEPROFILE + val[len(USERPROFILE):]
    else:
        safe_val = val

    print(f"osvar name={var}, exists={exists}, dollar={dollar}, spaces={spaces}, path={safe_val!r}")

for var in [
    "SYSTEMDRIVE",
    "SYSTEMROOT",
    "TEMP",
    "TMP",
    "USERPROFILE",
    "COMSPEC",
]:
    evar_path(var)

for drive, free in _cache_drive_free.items():
    print(f"drive name={drive!r}, free={free:.1f} MB")

Sample output with USERPROFILE rewritten to Z:\USERPROFILE:

osvar name=SYSTEMDRIVE, exists=1, dollar=0, spaces=0, path='C:'
osvar name=SYSTEMROOT, exists=1, dollar=0, spaces=0, path='C:\\Windows'
osvar name=TEMP, exists=0, dollar=1, spaces=0, path='Z:\\USERPROFILE\\AppData\\$TEMP'
osvar name=TMP, exists=1, dollar=0, spaces=0, path='Z:\\USERPROFILE\\AppData\\Local\\Temp'
osvar name=USERPROFILE, exists=1, dollar=0, spaces=0, path='Z:\\USERPROFILE'
osvar name=COMSPEC, exists=1, dollar=0, spaces=0, path='C:\\Windows\\system32\\cmd.exe'
drive name='c:', free=454958.0 MB
koubaa commented 3 months ago

I'll follow up on these.

I was wondering if it was a race condition in how VS2022 uses TMP, and asked the affected user to use num_jobs=1, and the issue persists.

koubaa commented 3 months ago 
C:\Dev\scripts\batches>pushd D:\Dev

D:\Dev>workon build
(build) D:\Dev>python the-test.py
osvar name=SYSTEMDRIVE, exists=1, dollar=0, spaces=0, path='C:'
osvar name=SYSTEMROOT, exists=1, dollar=0, spaces=0, path='C:\\Windows'
osvar name=TEMP, exists=1, dollar=0, spaces=0, path='Z:\\USERPROFILE\\AppData\\Local\\Temp'
osvar name=TMP, exists=1, dollar=0, spaces=0, path='Z:\\USERPROFILE\\AppData\\Local\\Temp'
osvar name=USERPROFILE, exists=1, dollar=0, spaces=0, path='Z:\\USERPROFILE'
osvar name=COMSPEC, exists=1, dollar=0, spaces=0, path='C:\\Windows\\system32\\cmd.exe'
drive name='c:', free=58225.2 MB

(build) D:\Dev>
jcbrill commented 3 months ago

@koubaa Sorry for the confusion with the implementation of the obfuscation.

There is nothing that jumps out concerning the environment variable configuration.

All the tests checks were done on the actual paths.

The Z:\USERPROFILE was chosen so that it would be reasonably easy to tell which paths were likely using the windows default USERPROFILE prefix (e.g., TEMP=%USERPROFILE%\AppData\Temp) versus a custom location (e.g., C:\Temp).

Some users are sensitive about having their username exposed. It certainly could have been done better.

It might be worth checking the security/permissions settings on the C:\Users\USERNAME\AppData\Local\Temp folder for the appropriate user name that invokes the build command.

It also might be worth testing settings of TEMP and TMP that are outside the windows system and user folders especially if the antivirus settings are less picky for folders outside the system/user folders (or a folder that can be explicitly added to the av exception list).

If a new temp folder is configured, the temp folder must exist.

Note to self:

bdbaddog commented 3 months ago

How much space is free on z: drive?

jcbrill commented 3 months ago

How much space is free on z: drive?

Z:\USERPROFILE is an alias for C:\Users\USERNAME. According to the output posted above, there is approximately 56.86 GB free on the c drive.

jcbrill commented 2 months ago

@koubaa I've attached a revised version of the earlier script. At your convenience, I would be interested in knowing if it works somewhere other than here.

scons-environ-2.zip contains a revised version of:

Run the attached script on the host computer in the same windows shell environment that SCons is invoked and redirect the output to a file:

python scons-environment.py >scons-environ-log.txt

Changes:

Caveats:

Sample output when run on a local computer:

Configuration:
    USE_SAFE_USERNAME=True (<USERNAME>)
    USE_SAFE_COMPUTERNAME=True (<COMPUTERNAME>)

Drive free space:
    C:    18,132.6 MB
    E:   100,308.1 MB

Environment paths:
    SYSTEMDRIVE='C:' (exists=True, nspecial=0)
    SYSTEMROOT='C:\\WINDOWS' (exists=True, nspecial=0)
    USERPROFILE='C:\\Users\\<USERNAME>' (exists=True, nspecial=0)
    COMSPEC='C:\\WINDOWS\\system32\\cmd.exe' (exists=True, nspecial=0)
    TMPDIR='' (exists=False, nspecial=0)
    TEMP='C:\\Users\\<USERNAME>\\AppData\\Local\\Temp' (exists=True, nspecial=0)
    TMP='C:\\Users\\<USERNAME>\\AppData\\Local\\Temp' (exists=True, nspecial=0)

Temporary file paths:
    TMPDIR='' (exists=False)
    TEMP='C:\\Users\\<USERNAME>\\AppData\\Local\\Temp' (exists=True)
        acl[0] NT AUTHORITY\SYSTEM:(I)(OI)(CI)(F)
        acl[1] BUILTIN\Administrators:(I)(OI)(CI)(F)
        acl[2] <COMPUTERNAME>\<USERNAME>:(I)(OI)(CI)(F)
        tempfile='C:\\Users\\<USERNAME>\\AppData\\Local\\Temp\\tmpj3kubeeo'
            acl[0] NT AUTHORITY\SYSTEM:(I)(F)
            acl[1] BUILTIN\Administrators:(I)(F)
            acl[2] <COMPUTERNAME>\<USERNAME>:(I)(F)
    TMP='C:\\Users\\<USERNAME>\\AppData\\Local\\Temp' (exists=True)
        acl[0] NT AUTHORITY\SYSTEM:(I)(OI)(CI)(F)
        acl[1] BUILTIN\Administrators:(I)(OI)(CI)(F)
        acl[2] <COMPUTERNAME>\<USERNAME>:(I)(OI)(CI)(F)
        tempfile='C:\\Users\\<USERNAME>\\AppData\\Local\\Temp\\tmpopsk03yw'
            acl[0] NT AUTHORITY\SYSTEM:(I)(F)
            acl[1] BUILTIN\Administrators:(I)(F)
            acl[2] <COMPUTERNAME>\<USERNAME>:(I)(F)
    <WinTemp>='C:\\WINDOWS\\Temp' (exists=True)
        acl[0]  Access is denied.
        tempfile='C:\\WINDOWS\\Temp\\tmpda1b0n_p'
            acl[0] NT AUTHORITY\SYSTEM:(I)(S,RD)
            acl[1] BUILTIN\IIS_IUSRS:(I)(S,RD)
            acl[2] BUILTIN\Administrators:(I)(F)
            acl[3] NT AUTHORITY\SYSTEM:(I)(F)
            acl[4] <COMPUTERNAME>\<USERNAME>:(I)(F)
    <PyDefault>='' (exists=False)
        tempfile='C:\\Users\\<USERNAME>\\AppData\\Local\\Temp\\tmp1mf9xmcy'
            acl[0] NT AUTHORITY\SYSTEM:(I)(F)
            acl[1] BUILTIN\Administrators:(I)(F)
            acl[2] <COMPUTERNAME>\<USERNAME>:(I)(F)
koubaa commented 2 months ago

Hello,

After a conversation with the Microsoft compiler team they believe it is a problem with scons. To check, we looked at procmon system logs of all the process creations (which includes the environment variables that are set). Here is what I found (I use 1-based indexing for PIDs for simplicity)

PID 1: python build_system.py PID 2 (parent=PID1): cmd.exe /c "scons.exe args..." PID 3 (parent=PID2): scons.exe args... PID 4 (parent=PID3): python scons.exe args... PID 5 (parent=PID4): path/to/python.exe scons.exe args... PID 6 (parent=PID5): cmd.exe /c "path/to/vcvars64.bat" & set PID 7 (parent=PID5): protoc.exe args... PID 8 (parent=PID5): cmd.exe /C "cl args...

In the above stack, only PID 8 does not have the TMP/TEMP environment variables set. protoc.exe is a compiler which I set up manually in the scons build using the site_scons/site_tools folder and it gets the TMP/TEMP env vars.

Finally only the cmd.exe /C "cl.exe" does not have the environment variables set

jcbrill commented 2 months ago

@koubaa When setting up protoc.exe, is the SCons system environment variable env[ENV] modified and/or written into?

Is there any chance that the setup is writing an empty string into the TEMP/TMP variable?

Effectively: env[ENV]["TEMP"] = "" env[ENV]["TMP"] = ""

I believe the TEMP/TMP variables are only retrieved when the Environment is constructed. Any inadvertent overwrites by SCons-code and/or user-code would likely cause the behavior exhibited.

mwichmann commented 2 months ago

This just seems really odd. The Windows platform code imports a few things specifically (with an admonition to consider carefully before adding more) - this is unrelated to whether or not the Microsoft compiler chain is even in use:

    import_env = ['SystemDrive', 'SystemRoot', 'TEMP', 'TMP', 'USERPROFILE']
    for var in import_env:                                                              v = os.environ.get(var)
        if v:
            env['ENV'][var] = v

So the only way you wouldn't get TEMP/TMP set is if they weren't in the Windows environment, or were set to an empty value. But you're saying another tool in a failing environment does get them, so missing/unset doesn't seem like it can be the reason. Is there anything in your build that could possibly overwrite the ENV construction variable in the environment used for the msvc build (probably conditionally, since not all your builds are broken)

koubaa commented 2 months ago

I use this:

env = Environment(
    tools=['default', 'protoc', 'csc'],
    ENV = {'PATH' : os.environ['PATH']},
    MSVC_USE_SCRIPT=vcvars_path)

The environment I pass to protoc is this:

env_copy = os.environ.copy()

maybe my issue is setting ENV on Environment in the first place. I could try removing that.

mwichmann commented 2 months ago

Yes, setting that way sets the value of ENV to what you specified, so wipes out any defaults. The Environment call doesn't presently provide for appending to construction vars. It's theoretically more correct to set up the env first, then in a subsequent step, append to PATH or whatever else you need to (there's an AppendENVPath method for that). That should work as long as the tools setup doesn't require those paths in order to work. I know there's advice in various places, and samples, that do exactly what you do, so it's pretty understandable. If your protoc tool needs a special path, you can defer the protoc setup until you've added the path, conceptually like:

env = Environment(MSVC_USE_SCRIPT=vcvars_path)
env.AppendENVPath('PATH', protoc_path)
env.Tool('protoc')

You may already be using it, if so never mind, but wanted to make sure you were aware there's a protoc tool in the Contrib repository ("unofficial", in other words) - https://github.com/SCons/scons-contrib/tree/master/sconscontrib/SCons/Tool/Protoc

bdbaddog commented 2 months ago

I use this:

env = Environment(
    tools=['default', 'protoc', 'csc'],
    ENV = {'PATH' : os.environ['PATH']},
    MSVC_USE_SCRIPT=vcvars_path)

The environment I pass to protoc is this:

env_copy = os.environ.copy()

maybe my issue is setting ENV on Environment in the first place. I could try removing that.

What is causing you to do the following? ENV = {'PATH' : os.environ['PATH']} ? Is this for protoc, csc, other?

If you're passing the MSVC_SCRIPT, you shouldn't need it for MSVC at all.. Also.. can you paste the code which "The environment I pass to protoc is this:" ? How are you running protoc? Is it not using the normal string action to call the tool which would propagate env['ENV'] to it?

koubaa commented 2 months ago

Thanks for the sharing the protoc tool. It didn't exist when I first set this up.

I don't do anything specifically for protoc. Actually the ENV = {'PATH': os.environ['PATH']} wasn't something I did or was even aware of... someone else had made that change to the SConstruct. I'm trying to track down why but I'm afraid I might not be able to figure out what issue that was supposed to work around.

Also.. can you paste the code which "The environment I pass to protoc is this:" ? How are you running protoc?

using subprocess.check_call(protoc_command_line, env=os.environ.copy())

The env is indeed propagated to this tool, but I only use it to set up protoc_command_line, e.g. for the protoc compiler location, the output file location, output language setting, command line arguments, etc. I don't use it in the subprocess environment at all.

mwichmann commented 2 months ago

... Actually the ENV = {'PATH': os.environ['PATH']} wasn't something I did or was even aware of... someone else had made that change to the SConstruct. I'm trying to track down why but I'm afraid I might not be able to figure out what issue that was supposed to work around.

The problem was almost certainly "some tool was not found by SCons" even though it workd just fine when I launched it from cmd.exe. It's not like we haven't seen that many times before, it's just the Big Hammer approach of fixing it that way may have side effects.

Also.. can you paste the code which "The environment I pass to protoc is this:" ?

How are you running protoc?

using subprocess.check_call(protoc_command_line, env=os.environ.copy())

Yes, that would bypass having lost the values expected to be in env['ENV'] because you're not passing env['ENV'] as the subprocess environment, you're passing a copy of the system one. So not surprised TMP/TEMP exist for that call.

koubaa commented 2 months ago

It's not like we haven't seen that many times before, it's just the Big Hammer approach

That's interesting. Does this mean that scons documentation mentions the env['ENV'] hack somewhere or that it shows up on a lot of forums/stackoverflow/etc? It sounds like you've seen it before many times

bdbaddog commented 2 months ago

It's not like we haven't seen that many times before, it's just the Big Hammer approach

That's interesting. Does this mean that scons documentation mentions the env['ENV'] hack somewhere or that it shows up on a lot of forums/stackoverflow/etc? It sounds like you've seen it before many times

It's in the FAQ..
Though the "better" way assuming you have a build environment which is similar for all of your engineers is to standardize locations for said tool and just append that path to PATH before initializing the Environment or tool, or if it's your own tool, or one you've placed site_scons/site_tools, you can add the likely local paths to the paths the tool would search for during tool initiialization.

koubaa commented 2 months ago

To be clear the use of 'ENV' in our build system is not necessary to find protoc. I'm still trying to find out why it was done and I plan to remove it.

But isn't it an issue if the scons FAQ suggests something which fails in such a subtle way when using a popular compiler (MSVC) ?

mwichmann commented 2 months ago

But isn't it an issue if the scons FAQ suggests something which fails in such a subtle way when using a popular compiler (MSVC) ?

Yes.

bdbaddog commented 2 months ago

But isn't it an issue if the scons FAQ suggests something which fails in such a subtle way when using a popular compiler (MSVC) ?

Yes.

That said.. this failure seems to be very rare in the wild.

Also there is this warning in the FAQ Of course, by propagating external environment variables into your build, you're running the risk that a change in the external environment will affect the build, possibly in unintended ways.

bdbaddog commented 2 months ago

But isn't it an issue if the scons FAQ suggests something which fails in such a subtle way when using a popular compiler (MSVC) ?

Yes.

That said.. this failure seems to be very rare in the wild.

Also there is this warning in the FAQ Of course, by propagating external environment variables into your build, you're running the risk that a change in the external environment will affect the build, possibly in unintended ways.

I guess the warning could be stronger... So does it look like TEMP was the culprit here?

koubaa commented 2 months ago

Of course, by propagating external environment variables into your build, you're running the risk that a change in the external environment will affect the build, possibly in unintended ways.

That isn't the same failure mode. Here, an external environment variable was not propagated and should have been.

bdbaddog commented 2 months ago

Of course, by propagating external environment variables into your build, you're running the risk that a change in the external environment will affect the build, possibly in unintended ways.

That isn't the same failure mode. Here, an external environment variable was not propagated and should have been.

Which one was it? I'm unclear..

jcbrill commented 2 months ago

Below is an example that intends to illustrate what is likely happening. In the interest of simplicity, only the MSVC tools are shown. Custom path additions would still need to be accounted for.

Method:

  1. Similar to what is described above and requires admin privileges to build successfully.
  2. Similar to 1, but passes entire os.environ via ENV and "works".
  3. Traditional msvc method which "works".

For windows, the following environment variables are set prior to user overrides: "SystemDrive", "SystemRoot", "TMP", "TEMP", and "USERPROFILE". These variables are likely not set again.

Method 1 below, similar to what you are experiencing, clobbers the predefined values by overwriting the entire ENV dictionary. The "TMP", "TMP", and "USERPROFILE" variables are now gone unless manually restored later.

The issue with method 1 is that the entire ENV dictionary is replaced with a dictionary containing only "PATH". When the MSVC script is run, additional ENV keys will be added (e.g., "INCLUDE", "LIB", "LIBPATH", etc., ...).

The issue with method 1 is that once the variables are overwritten, there is no way to "preserve" the original settings.

All: please advise of any overt misinformation.

import os

method = 1
MSVC_USE_SCRIPT = r"C:\Software\MSVS-2022-143-Com\VC\Auxiliary\Build\vcvars64.bat"

VariantDir("_build", "./src", duplicate=0)

check_evars = [
    # SCons.Platform.win32 (windows)
    "SystemDrive",
    "SystemRoot",
    "TMP",
    "TEMP",
    "USERPROFILE",
] + [
    # SCons.Tool.MSCommon.common (msvc)
    "INCLUDE",
    "LIB",
    "LIBPATH",
    "PATH",
    "VSCMD_ARG_app_plat",
    "VCToolsInstallDir",
]

if method == 1:

    # Fails w/o admin priviledges:
    #     LINK : fatal error LNK1104: cannot open file 'C:\Windows\lnk{0C756BDA-6CF3-42AC-AA28-AE066D713A57}.tmp'

    env=Environment(
        MSVC_USE_SCRIPT=MSVC_USE_SCRIPT,
        ENV={'PATH': os.environ["PATH"]},
        tools=['default']
    )
    env.Program("_build/hello", ["_build/hello.c"])

    # method=1
    #
    #   HAVE env[ENV]['SystemDrive'] False  <== CLOBBERED
    #   HAVE env[ENV]['SystemRoot'] True
    #   HAVE env[ENV]['TMP'] False          <== CLOBBERED
    #   HAVE env[ENV]['TEMP'] False         <== CLOBBERED
    #   HAVE env[ENV]['USERPROFILE'] False  <== CLOBBERED
    #
    #   HAVE env[ENV]['INCLUDE'] True
    #   HAVE env[ENV]['LIB'] True
    #   HAVE env[ENV]['LIBPATH'] True
    #   HAVE env[ENV]['PATH'] True
    #   HAVE env[ENV]['VSCMD_ARG_app_plat'] True
    #   HAVE env[ENV]['VCToolsInstallDir'] True

elif method == 2:

    # passes

    env=Environment(
        MSVC_USE_SCRIPT=MSVC_USE_SCRIPT,
        ENV=dict(os.environ),
        tools=['default']
    )
    env.Program("_build/hello", ["_build/hello.c"])

    # method=2
    #
    #   HAVE env[ENV]['SystemDrive'] True
    #   HAVE env[ENV]['SystemRoot'] True
    #   HAVE env[ENV]['TMP'] True
    #   HAVE env[ENV]['TEMP'] True
    #   HAVE env[ENV]['USERPROFILE'] True
    #
    #   HAVE env[ENV]['INCLUDE'] True
    #   HAVE env[ENV]['LIB'] True
    #   HAVE env[ENV]['LIBPATH'] True
    #   HAVE env[ENV]['PATH'] True
    #   HAVE env[ENV]['VSCMD_ARG_app_plat'] True
    #   HAVE env[ENV]['VCToolsInstallDir'] True

elif method == 3:

    # passes

    env=Environment(
        MSVC_VERSION="14.3",
        tools=['default']
    )
    env.Program("_build/hello", ["_build/hello.c"])

    # method=3
    # 
    #   HAVE env[ENV]['SystemDrive'] True
    #   HAVE env[ENV]['SystemRoot'] True
    #   HAVE env[ENV]['TMP'] True
    #   HAVE env[ENV]['TEMP'] True
    #   HAVE env[ENV]['USERPROFILE'] True
    # 
    #   HAVE env[ENV]['INCLUDE'] True
    #   HAVE env[ENV]['LIB'] True
    #   HAVE env[ENV]['LIBPATH'] True
    #   HAVE env[ENV]['PATH'] True
    #   HAVE env[ENV]['VSCMD_ARG_app_plat'] True
    #   HAVE env[ENV]['VCToolsInstallDir'] True

else:

    raise NotImplementedError(f"method={method} is not supported")

def check_ENV(env, evars):
    ENV_set = set(key.upper() for key in env["ENV"].keys())
    print(f"method={method}")
    for key in evars:
        print(f"  HAVE env[ENV][{key!r}] {key.upper() in ENV_set}")

check_ENV(env, check_evars)
bdbaddog commented 2 months ago

@jcbrill - as usual.. Excellent explanation.. I was staring right at it and didn't see it! Thanks.

koubaa commented 2 months ago

For what it's worth, I had switched to method 3 which fixed the build as admin issue for the users that affected. But that broke a linux build for another user (scons couldn't find the compiler). Method 2 fixes that issue.

Would it make sense for method 2 to appear in the FAQ rather than method 1?

mwichmann commented 2 months ago

there's a faq update pending, just have to get the wheels turned