Process.OutputDataReceived not firing

[Fabi]

I'm using something like an attach/detach function to get the process console output redirected to a main console only.

To achieve this I'm using the process.BeginOutputReadLine and process.CancelOutputRead for my attach/detach together with the OutputDataReceived event.

However I noticed that after calling process.CancelOutputRead once and using process.BeginOutputReadLine after that, the OutputDataReceived won't fire at all.

I created a test console app with .NET Core 2.2 and .NET Core 3.0 and faced this issue on both.
I also created a console app with .NET Framework 4.7 and it work's without problems there, so it looks like a .NET Core specific problem.

I found the issue https://github.com/dotnet/corefx/issues/31740 and used the test code from it and adjusted it a bit, but not sure if it's related to this:

using System;
using System.IO;
using System.Text;
using System.Threading;
using System.Diagnostics;

class EmptyStdOutRepro
{

    public static void Main()
    {
        new EmptyStdOutRepro().Run();
    }

    public void Run()
    {

        while (true)
            Exec();

    }

    private void Exec()
    {

        int lineCount = 0;
        string output = "";

        Process process = new Process();

        process.StartInfo.FileName = "ipconfig.exe";

        process.StartInfo.UseShellExecute = false;
        process.StartInfo.RedirectStandardOutput = true;
        process.StartInfo.CreateNoWindow = true;
        process.StartInfo.ErrorDialog = false;

        process.OutputDataReceived += new DataReceivedEventHandler((sender, e) =>
        {

            output = "fired";

        });

        process.Start();

        process.BeginOutputReadLine();
        process.CancelOutputRead();
        process.BeginOutputReadLine();
        process.WaitForExit();

        if (output != "")
            Console.WriteLine("PASSED!" + output.Length);
        else
            Console.WriteLine("FAILED!" + output.Length);

        process.WaitForExit();
        process.Close();

    }

}

.NET Core --info

dotnet --info
.NET Core SDK (reflecting any global.json):
 Version:   3.0.100-preview-009801
 Commit:    559dea258d

Runtime Environment:
 OS Name:     Windows
 OS Version:  10.0.17134
 OS Platform: Windows
 RID:         win10-x64
 Base Path:   C:\Program Files\dotnet\sdk\3.0.100-preview-009801\

Host (useful for support):
  Version: 3.0.0-preview-27122-01
  Commit:  00c5c8bc40

.NET Core SDKs installed:
  2.1.500 [C:\Program Files\dotnet\sdk]
  3.0.100-preview-009782 [C:\Program Files\dotnet\sdk]
  3.0.100-preview-009801 [C:\Program Files\dotnet\sdk]

.NET Core runtimes installed:
  Microsoft.AspNetCore.All 2.1.6 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.App 2.1.6 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.0.0-alpha1-10772 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.0.0-preview-18577-0031 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 2.1.6 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.0.0-preview-27122-01 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.WindowsDesktop.App 3.0.0-alpha-27122-4 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 3.0.0-alpha-27128-4 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]

[Fabi]

Any news about that^^? I wasn't able to find anything to workaround this. It actually breaks my whole parent/child console logging

[stephentoub]

No news, other than it is a bug. The implementation in core is assuming that once canceled, it should stop processing permanently, which is not what the docs describe:

https://docs.microsoft.com/en-us/dotnet/api/system.diagnostics.process.canceloutputread?view=netframework-4.7.2

When you call CancelOutputRead, all in-progress read operations for StandardOutput are completed and then the event handler is disabled. All further redirected output to StandardOutput is saved in a buffer. If you re-enable the event handler with a call to BeginOutputReadLine, the saved output is sent to the event handler and asynchronous read operations resume. If you want to change the event handler before resuming asynchronous read operations, you must remove the existing event handler before adding the new event handler...

[MarcoRossignoli]

@stephentoub maybe I found the issue CancelOutputRead signal CTS of AsyncStreamReader and BeginOutputReadLine doesn't re-create it(or CancelOutputRead nulls ref), so ReadBufferAsync exit with OperationCanceledException, I could try to fix it if you agree.

[stephentoub]

@MarcoRossignoli, it's a bit more than that; the whole reading implementation is broken for this case, as to match what the docs describe, it shouldn't stop reading at all when cancellation occurs... instead it needs to continue to read and buffer, just not invoke the callback, as netfx does. If you want to try fixing it, go for it :)

[MarcoRossignoli]

the saved output is sent to the event handler and asynchronous read operations resume

Oh sorry I did't read properly...risky behaviour could lead to OOM, isn't it?

[GSPP]

I guess it would not read anything from the underlying stream in that case. This would not OOM but not allow the pipe to drain. It might block the child process (which is a common bug when someone forgets to read StdErr). So that risk is nothing new and it's an esoteric scenario to stop reading output after you have started. Actually, I wonder what your scenario is. Why are you doing this?

[stephentoub]

I guess it would not read anything from the underlying stream in that case.

Unfortunately both the docs and the netfx implementation disagree: "All further redirected output to StandardOutput is saved in a buffer. If you re-enable the event handler with a call to BeginOutputReadLine, the saved output is sent to the event handler and asynchronous read operations resume."

risky behaviour could lead to OOM, isn't it?

Yes, but it is what it is.

So that risk is nothing new and it's an esoteric scenario to stop reading output after you have started.

I agree. In which case I think it's better to be compatible with netfx and the docs.

[GSPP]

Man, the Process API is so misdesigned. See https://github.com/dotnet/corefx/issues/3483. I constantly see people failing to use Process on Stack Overflow and I myself have failed using it correctly in multiple ways.

[MarcoRossignoli]

@stephentoub silly question...If I would like to know if some api will throw PNSE on some plat without using analyzer?Is there a way to infer it from documentation?

[stephentoub]

If I would like to know if some api will throw PNSE on some plat without using analyzer?Is there a way to infer it from documentation?

I don't believe docs have been updated with that information, at least not fully.

[MarcoRossignoli]

@stephentoub seems that netfx doesn't respect guide, I did some tests and on "cancel state" code drain queue https://referencesource.microsoft.com/#System/services/monitoring/system/diagnosticts/AsyncStreamReader.cs,278
What do you think we need to respect?Doc or netfx?

[stephentoub]

I did some tests

Can you share your tests?

[MarcoRossignoli]

Can you share your tests?

Sure dotnet/corefx@master...MarcoRossignoli:process
Test check if there are gaps in sequence after stop, and fail also in netfx.

[stephentoub]

You're right. This call:
https://referencesource.microsoft.com/#System/services/monitoring/system/diagnosticts/AsyncStreamReader.cs,262
causes the buffer to emptied. So the docs are just wrong.

[MarcoRossignoli]

So the docs are just wrong.

Should I open an issue on docs repo?

[stephentoub]

Sure, thanks.

[Fabi]

So we actually have two issues here?

1. It’s not buffering as stated in the docs (well a doc issue)
2. And it’s not outputting any data on calling beginread again after canceling. (That definitively needs to be fixed)

[danmoseley]

@MarcoRossignoli is this fixed, with your change? I'm now confused as to what this issue tracks that's left.

[MarcoRossignoli]

@danmosemsft we need to merge dotnet/corefx#33974 to fix it. The other PR is for guide that I fixed dotnet/dotnet-api-docs#1467