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

FailFast in System.ConsolePal.WindowsConsoleStream.WriteFileNative #24508

Open
danmosemsft opened this Issue Oct 9, 2017 · 6 comments

Comments

Projects
None yet
4 participants
@danmosemsft
Copy link
Member

danmosemsft commented Oct 9, 2017

While debugging OpenCover, which invoked xunit.console, if I select in the console (to block console output) I sometimes get a failfast as below.

In this case, writeSuccess is true, but count == 50 and numBytesWritten is 100. The string to write is 50 characters: "xUnit.net console test runner (64-bit .NET Core).\n". MSDN seems clear that count is in bytes, however. Note: this is on RS3.

MSDN says

If the pipe buffer is full when an application uses the WriteFile function to write to a pipe, the write operation may not finish immediately. The write operation will be completed when a read operation (using the ReadFile function) makes more system buffer space available for the pipe.
When writing to a non-blocking, byte-mode pipe handle with insufficient buffer space, WriteFile returns TRUE with *lpNumberOfBytesWritten < nNumberOfBytesToWrite.

Of course, this is the reverse situation but perhaps the assert would fail in this case also. I assume that WriteFile wants you to call it again for the remainder in this case (which we don't do)

Console.OutputEncoding.CodePage=437 (OEM)

                    if (useFileAPIs)
                    {
                        int numBytesWritten;
                        writeSuccess = (0 != Interop.Kernel32.WriteFile(hFile, p + offset, count, out numBytesWritten, IntPtr.Zero));
                        Debug.Assert(!writeSuccess || count == numBytesWritten);  <<<<<
                    }
Cannot instrument C:\git\corefx\bin\testhost\netcoreapp-Windows_NT-Debug-x64\shared\Microsoft.NETCore.App\9.9.9\System.Private.CoreLib.dll as no PDB/MDB could be loaded
xUnit.net console test runner (64-bit .NET Core)
FailFast:

   at System.Diagnostics.Debug.Assert(Boolean condition, String message, String detailMessage) in E:\A\_work\1111\s\src\mscorlib\shared\System\Diagnostics\Debug.cs:line 97
   at System.Diagnostics.Debug.Assert(Boolean condition) in E:\A\_work\1111\s\src\mscorlib\shared\System\Diagnostics\Debug.cs:line 80
   at System.ConsolePal.WindowsConsoleStream.WriteFileNative(IntPtr hFile, Byte[] bytes, Int32 offset, Int32 count, Boolean useFileAPIs) in C:\git\corefx\src\System.Console\src\System\ConsolePal.Windows.cs:line 1210
   at System.ConsolePal.WindowsConsoleStream.Write(Byte[] buffer, Int32 offset, Int32 count) in C:\git\corefx\src\System.Console\src\System\ConsolePal.Windows.cs:line 1131
   at System.IO.StreamWriter.Flush(Boolean flushStream, Boolean flushEncoder) in C:\git\corefx\src\System.Runtime.Extensions\src\System\IO\StreamWriter.cs:line 260
   at System.IO.StreamWriter.WriteLine(String value) in C:\git\corefx\src\System.Runtime.Extensions\src\System\IO\StreamWriter.cs:line 554
   at System.IO.SyncTextWriter.WriteLine(String value) in C:\git\corefx\src\System.Console\src\System\IO\SyncTextWriter.cs:line 280
   at System.IO.TextWriter.WriteLine(String format, Object arg0, Object arg1) in C:\git\corefx\src\System.Runtime.Extensions\src\System\IO\TextWriter.cs:line 484
   at System.Console.WriteLine(String format, Object arg0, Object arg1) in C:\git\corefx\src\System.Console\src\System\Console.cs:line 566
   at Xunit.ConsoleClient.Program.Main(String[] args)

   at System.Environment.FailFast(System.String, System.Exception)
   at System.Diagnostics.Debug.ShowAssertDialog(System.String, System.String, System.String)
   at System.Diagnostics.Debug.Assert(Boolean, System.String, System.String)
   at System.Diagnostics.Debug.Assert(Boolean)
   at System.ConsolePal+WindowsConsoleStream.WriteFileNative(IntPtr, Byte[], Int32, Int32, Boolean)
   at System.ConsolePal+WindowsConsoleStream.Write(Byte[], Int32, Int32)
   at System.IO.StreamWriter.Flush(Boolean, Boolean)
   at System.IO.StreamWriter.WriteLine(System.String)
   at System.IO.SyncTextWriter.WriteLine(System.String)
   at System.IO.TextWriter.WriteLine(System.String, System.Object, System.Object)
   at System.Console.WriteLine(System.String, System.Object, System.Object)
   at Xunit.ConsoleClient.Program.Main(System.String[])
C
@mikedn

This comment has been minimized.

Copy link
Collaborator

mikedn commented Oct 9, 2017

That assert is dubious, AFAIR there is no guarantee that WriteFile writes all the requested bytes. It will probably do so when writing to the actual console but the output may be redirected to a pipe and that's another story.

@danmosemsft

This comment has been minimized.

Copy link
Member Author

danmosemsft commented Oct 9, 2017

@mikedn the interesting thing here is that count < numBytesWritten.

@mikedn

This comment has been minimized.

Copy link
Collaborator

mikedn commented Oct 9, 2017

the interesting thing here is that count < numBytesWritten.

Ah, that's funny. It does looks like a mix up between bytes and chars 😄

@danmosemsft

This comment has been minimized.

Copy link
Member Author

danmosemsft commented Oct 9, 2017

In the case where count > numBytesWritten,

The write operation will be completed when a read operation (using the ReadFile function) makes more system buffer space available for the pipe

are we supposed to call WriteFile again (with an incremented pointer/lower count)? I'm not sure what else it would mean, since we can't just carry on and let it read more from our buffer at an arbitrary future time.

@mikedn

This comment has been minimized.

Copy link
Collaborator

mikedn commented Oct 9, 2017

are we supposed to call WriteFile again (with an incremented pointer/lower count)?

Yes, that's how it usually works. However, I doubt that it is needed here, note that the MSDN doc refers to pipes opened in non-blocking mode, that's a very unusual case.

It's also a very different situation than the issue you're experiencing.

@stephentoub

This comment has been minimized.

Copy link
Member

stephentoub commented Oct 9, 2017

the MSDN doc refers to pipes opened in non-blocking mode, that's a very unusual case.

Agreed, although interestingly we recently hit upon that situation on Linux in a docker container, and needed to add explicit blocking to address it.
#23539
I wonder if there's a similar docker situation to be handled on the Windows side.

@joperezr joperezr added the bug label Nov 21, 2017

@joperezr joperezr modified the milestones: 2.1.0, Future Nov 21, 2017

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment