FailFast in System.ConsolePal.WindowsConsoleStream.WriteFileNative

[danmoseley]

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]

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.

[danmoseley]

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

[mikedn]

the interesting thing here is that count < numBytesWritten.

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

[danmoseley]

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]

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]

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.
dotnet/corefx#23539
I wonder if there's a similar docker situation to be handled on the Windows side.

[carlossanlop]

Triage: @danmosemsft it looks that the assert problem was addressed with this commit:
ada4b3c
Is anything else to address from this issue?

[danmoseley]

I don't think we're going to investigate further without reports of an issue. So we can close this.