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

NtCreateFile: Too many open. (Was: Missing TLBREF.dll and warning about "System.Text.Json.JsonEncodedText") #153

Open
kmatheussen opened this issue Nov 18, 2024 · 14 comments

Comments

@kmatheussen
Copy link

Hi,

After setting up msvc-wine msbuild fails with an error message that it couldn't launch "c1xx.dll". I tracked this error down to a missing TLBREF.dll file. After copying the TLBREF.dll file from my windows computer into directory of "c1xx.dll", I get this warning:

Could not load signature of System.Text.Json.JsonEncodedText:Encode due to: Could not load file or assembly 'System.Text.Encodings.Web, Version=8.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51' or one of its dependencies.

...and the build just stops. The last call to CL.exe just runs forever without using any CPU. The reason for this seems to be that CL.exe is given more than one source file, which I guess is not normal. E.g. like this: "CL.exe a.cpp b.cpp c.cpp d.cpp" (not the actual line, it's just to illustrate.

If I run the CL.exe command that fails one by one, one source at a time, things work. But there's thousands of files in my project and I can't do this manually every time.

So my theory is that at least two of these three mysterious things are connected: 1. the missing TLBREF.dll file, 2 The warning about "System.Text.Json.JsonEncodedText", and 3. more than one source file given as argument to CL.exe.

I've googled the System.Text warning, and it seems to be a common problem, but no clear solution. My theory is that msbuild is reading json files the wrong way and that's why wrong arguments are given to CL.exe.

Anyhow, any ideas what to do?

@mstorsjo
Copy link
Owner

CC @ravenexp wrt msbuild

Can you reproduce the issue with cl.exe a.cpp b.cpp outside of msbuild? I just tested that and it seemed to work fine for me without the msbuild context.

@kmatheussen
Copy link
Author

Yes, and I've double-checked again now to be sure. Neither of the two commands below work. They don't seem to do anything, and never finishes:

  1. Run directly with wine:

wine64 g:\my_msvc\opt\msvc\vc\tools\msvc\14.42.34433\bin\Hostx64\x64\CL.exe /c /I"G:\fotostation_macwin64_qt6_crosscompile\common64\FWLibs\\Libraries\X MP-Toolkit-SDK\public\include" /I"G:\fotostation_macwin64_qt6_crosscompile\common64\FWLibs\Libraries\dng_sdk\projects\win\dng_sdk\..\..\..\..\zlib-1.2.13" /I../../../../dng_sdk/source /I../../../../xmp/toolkit/public/include /I"../../../../xmp/toolkit/third-party/zlib" /Zi /nologo /W3 /WX- /diagnostics:column /MP /Od /Os /D WIN32 /D _DEBUG /D qDNGValidate=0 /D qDNGValidate=0 /D WIN64 /D qDNGDebug=0 /D NDEBUG /D _CONSOLE /D _CRT_SECURE_NO_DEPRECATE /D WIN32 /D qWinOS=1 /D qMacOS=0 /D qVisualC=1 /D _WINDOWS=1 /D BIB_MULTI_THREAD=1 /D _VC80_UPGRADE=0x0710 /D _UNICODE /D UNICODE /D qWinUniversal /Gm- /EHsc /MDd /GS /fp:precise /Zc:wchar_t /Zc:forScope /Zc:inline /Fo"G:\fotostation_macwin64_qt6_crosscompile\Projects\Win\\_buildtemp\dng_sdk\x64\Debug\\" /Fd"G:\fotostation_macwin64_qt6_crosscompile\Projects\Win\Output\dng_sdk_d.pdb" /external:W3 /Gd /TP /FC /errorReport:queue ..\..\..\source\dng_abort_sniffer.cpp ..\..\..\source\dng_area_task.cpp

  1. Run using the "cl" script provided by msvc-wine:

cl /c /I"G:\fotostation_macwin64_qt6_crosscompile\common64\FWLibs\\Libraries\X MP-Toolkit-SDK\public\include" /I"G:\fotostation_macwin64_qt6_crosscompile\common64\FWLibs\Libraries\dng_sdk\projects\win\dng_sdk\..\..\..\..\zlib-1.2.13" /I../../../../dng_sdk/source /I../../../../xmp/toolkit/public/include /I"../../../../xmp/toolkit/third-party/zlib" /Zi /nologo /W3 /WX- /diagnostics:column /MP /Od /Os /D WIN32 /D _DEBUG /D qDNGValidate=0 /D qDNGValidate=0 /D WIN64 /D qDNGDebug=0 /D NDEBUG /D _CONSOLE /D _CRT_SECURE_NO_DEPRECATE /D WIN32 /D qWinOS=1 /D qMacOS=0 /D qVisualC=1 /D _WINDOWS=1 /D BIB_MULTI_THREAD=1 /D _VC80_UPGRADE=0x0710 /D _UNICODE /D UNICODE /D qWinUniversal /Gm- /EHsc /MDd /GS /fp:precise /Zc:wchar_t /Zc:forScope /Zc:inline /Fo"G:\fotostation_macwin64_qt6_crosscompile\Projects\Win\\_buildtemp\dng_sdk\x64\Debug\\" /Fd"G:\fotostation_macwin64_qt6_crosscompile\Projects\Win\Output\dng_sdk_d.pdb" /external:W3 /Gd /TP /FC /errorReport:queue ..\..\..\source\dng_abort_sniffer.cpp ..\..\..\source\dng_area_task.cpp

But if I remove the last ".cpp" file in any of these two commands, so that only one .cpp file is compiled, it seems to work.

@ravenexp
Copy link
Contributor

ravenexp commented Nov 18, 2024

I cannot reproduce this issue with msbuild. I made a new clean install of msvc-wine, and then ran:

msbuild /p:Platform=Win32 /p:PlatformToolset=v143

for this project: https://github.com/microsoft/Windows-classic-samples/tree/main/Samples/WinhttpProxy

I've checked that msbuild indeed invoked cl.exe with multiple source files in the command line:

ClCompile:
  z:\opt\msvc\vc\tools\msvc\14.42.34433\bin\HostX64\x86\CL.exe /c /ZI /JMC /nologo /W4 /WX /di
  agnostics:column /Od /Oy- /D WIN32 /D _DEBUG /D _CONSOLE /D _UNICODE /D UNICODE /Gm- /EHsc /
  RTC1 /MDd /GS /fp:precise /Zc:wchar_t /Zc:forScope /Zc:inline /Fo"WinhttpP.2C0E27FE\Debug\\"
   /Fd"WinhttpP.2C0E27FE\Debug\vc143.pdb" /external:W4 /Gd /TP /analyze- /FC /errorReport:queu
  e GetProxy.cpp WinhttpProxySample.cpp
  GetProxy.cpp
  WinhttpProxySample.cpp
  Generating Code...

The build was successful.

@mstorsjo
Copy link
Owner

Regarding running directly with wine - the wine-msvc.sh script does a bit of trickery around background processes, in particular in combination with the msvctricks.exe helper executable. (But that was mostly for cases when a separate longrunning background mspdbsrv.exe was started - here I would presume that all background processes do terminate at the same time as the actual compilation.)

For the example with the cl script, can you reduce that down to a minimal repro that involves the minimum amount of command line switches and minimal input source files?

@kmatheussen
Copy link
Author

Yes, I'll try to minimize. Also, running "msbuild /p:Platform=Win32 /p:PlatformToolset=v143 cpp/WinhttpProxySample.sln" succeeded, and all the test scripts in the "test" directory works as well.

@kmatheussen
Copy link
Author

This was hard. The problem seems to be caused by a combination of flags, and I had to go back and forth adding back commands that seemingly didn't cause the problem. I'm not sure if you can reproduce this, but I've come up with the following:

a.cpp:



void hello(void)
{
}

b.cpp:



void hello2(void)
{
}

And then in a bash terminal, I run the following:

STUFF_BIN=/home/kjetil/my_msvc/opt/msvc/bin/x64

. $STUFF_BIN/msvcenv.sh

export PATH=$STUFF_BIN:$PATH

cl /c /Zi /MP /external:W3 a.cpp b.cpp

And this is the output (cl never finished):

kjetil@fedora:~/fotostation_macwin64_qt6_crosscompile/temp$ cl /c /Zi /MP /external:W3 a.cpp b.cpp
Microsoft (R) C/C++ Optimizing Compiler Version 19.42.34433 for x64
Copyright (C) Microsoft Corporation.  All rights reserved.

a.cpp
b.cpp

@kmatheussen
Copy link
Author

The "/Zi" and "/external:W3" options I'm not too sure about. At least "/external:W3" I wouldn't be surprised is unrelated. But the "/MP" option is a surely related to the problem somehow. You have to go back and forth and try out combinations and order of combinations.

@kmatheussen
Copy link
Author

And by order of combinations, I don't mean that there's a difference between e.g. "/Zi /MP" and "/MP /Zi", although that might be the case also, I haven't checked, but I mean that it might work to first only use the "/MP" option, but the next time it fails, and when you add back the "/Zi" option it works, but the next time it fails again. However the sure thing seems to be that it always fails with both "/Zi" and "/MP", and possibly "/external:W3". It seems like there is a state remembered between each time cl is run.

@kmatheussen
Copy link
Author

When I run this line: WINEDEBUG=+all wine64 CL.exe /c /Zi /MP /external:W3 a.cpp b.cpp

I get a lot of lines printed out that ends with this:

....
....
25317.497:0948:07d0:trace:file:NtWriteFile (0x84,0x88,(nil),(nil),0x7fffff0fd9e8,0x7fffffafe610,0x00000116,(nil),(nil))
25317.498:0948:07d0:Ret  ntdll.NtWriteFile() retval=00000000 ret=6fffff41aad5
25317.498:0948:07d0:Call ucrtbase.free(7fffffafe610) ret=6fffff4128a1
25317.498:0948:07d0:Call KERNEL32.HeapFree(7fffff7a0000,00000000,7fffffafe610) ret=6ffffff92a2f
25317.498:0948:07d0:trace:heap:RtlFreeHeap handle 00007FFFFF7A0000, flags 0, ptr 00007FFFFFAFE610, return 1, status 0.
25317.498:0948:07d0:Ret  KERNEL32.HeapFree() retval=00000001 ret=6ffffff92a2f
25317.498:0948:07d0:Ret  ucrtbase.free() retval=00000001 ret=6fffff4128a1
25317.498:0948:07d0:Call ucrtbase.free(7fffffafdab0) ret=6fffff4141eb
25317.498:0948:07d0:Call KERNEL32.HeapFree(7fffff7a0000,00000000,7fffffafdab0) ret=6ffffff92a2f
25317.498:0948:07d0:trace:heap:RtlFreeHeap handle 00007FFFFF7A0000, flags 0, ptr 00007FFFFFAFDAB0, return 1, status 0.
25317.498:0948:07d0:Ret  KERNEL32.HeapFree() retval=00000001 ret=6ffffff92a2f
25317.498:0948:07d0:Ret  ucrtbase.free() retval=00000001 ret=6fffff4141eb
25317.498:0948:07d0:trace:rpc:I_RpcReceive (00007FFFFF0FDD00)
25317.498:0948:07d0:trace:rpc:RPCRT4_ReceiveWithAuth (00007FFFFFAFE4C0, 00007FFFFF0FDBB8, 00007FFFFF0FDD00, 0000000000000000)
25317.498:0948:07d0:trace:rpc:RPCRT4_default_receive_fragment (00007FFFFFAFE4C0, 00007FFFFF0FDBB8, 00007FFFFF0FDB28)
25317.498:0948:07d0:Call ntdll.NtReadFile(00000084,00000088,00000000,00000000,7fffffafe5b8,7fffff0fda68,7fff00000010,00000000,00000000) ret=6fffff41a9eb
25317.498:0948:07d0:trace:file:NtReadFile (0x84,0x88,(nil),(nil),0x7fffffafe5b8,0x7fffff0fda68,0x00000010,(nil),(nil))
25317.498:0948:07d0:Ret  ntdll.NtReadFile() retval=00000103 ret=6fffff41a9eb
25317.498:0948:07d0:Call KERNEL32.WaitForSingleObject(00000088,ffffffff) ret=6fffff41aa21
25317.498:0948:07d0:Call ntdll.NtWaitForMultipleObjects(00000001,7fffff0fd710,00000001,00000000,00000000) ret=6fffffcb1e51

So it's probably some kind of deadlock.

@kmatheussen
Copy link
Author

Ok, I think I found the reason, but it's a bit sketchy. Firstly I ran bt all in winedbg, and found this line: 0bb8:err:winediag:NtCreateFile Too many open files, ulimit -n probably needs to be increased, so after running "ulimit -n 64000", it usually works. I've run the line maybe 20 times, and only one time did it fail.

However, 'man systemd.exec` says the following:

LimitNOFILE=     │ ulimit -n         │ Number of File Descriptors │ Don't use. Be careful when      │
           │                  │                   │                            │ raising the soft limit above    │
           │                  │                   │                            │ 1024, since select(2) cannot    │
           │                  │                   │                            │ function with file descriptors  │
           │                  │                   │                            │ above 1023 on Linux.

which explains why it's 100% impossible on Fedora, (looks like), to increase the default value above 1024 except running "ulimit -n".

So this doesn't seem like the perfect solution. I guess there could be some bug somewhere in wine that's creating too many file descriptors?

@mstorsjo
Copy link
Owner

Thanks for the reduced testcase! For some reason, I'm not running into this issue either. (Normally I run with a persistent wineserver which is started with a raised ulimit -n already, but I tested by stopping that and let it start a new one with the default setting.) So with MSVC 17.12 and Wine 9.0, this combo does seem to work mostly fine. (Or perhaps I'm just ending up slightly below the limit for some reason.)

@mstorsjo
Copy link
Owner

Actually, nevermind, I did manage to reproduce it when executing with the default ulimit -n.

@huangqinjin
Copy link
Contributor

Looks like it doesn't related to ulimit -n. The long-living background process mspdbsrv.exe launched by cl.exe occasionally keeps cl.exe's stdout open.

export WINEDEBUG=-all
export WINE_MSVC_STDOUT=wine.log.stdout
export WINE_MSVC_STDERR=wine.log.stderr
export BINDIR=/opt/msvc/VC/Tools/MSVC/14.42.34226/bin/Hostx64/x64/

touch {1..16}.cpp

for i in {1..10}; do 
    echo $i
    wineserver -k
    wine /opt/msvc/bin/msvctricks.exe ${BINDIR}cl.exe /c /Zi /MP8 {1..16}.cpp
    lsof +c0 wine.log.* 2>/dev/null | grep wine
done

The output looks like below. I don't think the behaviour is correct, a background process should not inherit stdout from its parent. Not sure it is the actuall behaviour of cl.exe/mspdbsrv.exe, or it is a bug of wine.

1
mspdbsrv.exe 164910 huangqinjin 34u   REG   0,53      119 111225695 wine.log.stdout
mspdbsrv.exe 164910 huangqinjin 39u   REG   0,53      119 111225695 wine.log.stdout
mspdbsrv.exe 164910 huangqinjin 54u   REG   0,53      119 111225695 wine.log.stdout
2
mspdbsrv.exe 165067 huangqinjin 48u   REG   0,53      119 111225695 wine.log.stdout
mspdbsrv.exe 165067 huangqinjin 53u   REG   0,53      119 111225695 wine.log.stdout
mspdbsrv.exe 165067 huangqinjin 54u   REG   0,53      119 111225695 wine.log.stdout
3
4
5
mspdbsrv.exe 165540 huangqinjin 40u   REG   0,53      119 111225695 wine.log.stdout
mspdbsrv.exe 165540 huangqinjin 58u   REG   0,53      119 111225695 wine.log.stdout
6
mspdbsrv.exe 165700 huangqinjin 41u   REG   0,53      119 111225695 wine.log.stdout
mspdbsrv.exe 165700 huangqinjin 44u   REG   0,53      119 111225695 wine.log.stdout
7
mspdbsrv.exe 165853 huangqinjin 40u   REG   0,53      119 111225695 wine.log.stdout
mspdbsrv.exe 165853 huangqinjin 48u   REG   0,53      119 111225695 wine.log.stdout
8
mspdbsrv.exe 166017 huangqinjin 44u   REG   0,53      119 111225695 wine.log.stdout
9
mspdbsrv.exe 166177 huangqinjin 40u   REG   0,53      119 111225695 wine.log.stdout
10
mspdbsrv.exe 166333 huangqinjin 41u   REG   0,53      119 111225695 wine.log.stdout

@huangqinjin
Copy link
Contributor

Not sure it is the actuall behaviour of cl.exe/mspdbsrv.exe, or it is a bug of wine.

Tested on Windows and checked with Process Explorer, mspdbsrv.exe doesn't keep reference to cl.exe's stdout.

From the output above, sometimes stdout get opened multiple times, if I decrease the /MP parameter, the phenomenon also reduced. So it looks like to me a race in wineserver.

@kmatheussen kmatheussen changed the title Missing TLBREF.dll and warning about "System.Text.Json.JsonEncodedText" NtCreateFile: Too many open. (Was: Missing TLBREF.dll and warning about "System.Text.Json.JsonEncodedText") Nov 26, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants