C# - 자식 프로세스의 출력이 4,096보다 많은 경우 Process.WaitForExit 호출 시 hang 현상
재현 코드를 만들어 볼까요? ^^
우선, 자식 프로세스를 실행하는 코드는 이렇게 RedirectStandardOutput = true로 설정했을 때입니다.
using System.Diagnostics;
internal class Program
{
static void Main(string[] args)
{
ProcessStartInfo psi = new ProcessStartInfo();
psi.FileName = "ConsoleApp2.exe";
psi.UseShellExecute = false; /* 닷넷 프레임워크의 경우 기본값이 true */
psi.RedirectStandardOutput = true;
Process? process = Process.Start(psi);
if (process != null)
{
TimeSpan waitTime = TimeSpan.FromSeconds(3);
if (process.WaitForExit((int)waitTime.TotalMilliseconds) == false)
{
Console.WriteLine($"# Timeout: {waitTime}");
return;
}
string result = process.StandardOutput.ReadToEnd();
Console.WriteLine(result);
}
}
}
그리고 실행되는 자식 프로세스는 콘솔에 4K + 1 문자열을 출력합니다.
internal class Program
{
static void Main(string[] args)
{
string text = new string('a', 1024 * 3 + 1024 + 1); // 4096 + 1 문자열 출력
Console.Write(text);
}
}
위와 같이 코드를 작성하고 실행하면, 부모 프로세스에서 WaitForExit를 호출했을 때 hang 현상이 발생하고, 설정해 두었던 10초가 지나서야 timeout으로 벗어나게 됩니다.
왜 이런 걸까요? ^^
이 현상은 서버에서 Redirect로 받아주는 Output 버퍼가 4096 바이트로 제한돼 있기 때문입니다. (있기 때문으로 보입니다. ^^)
그래서인지, 자식 프로세스는 4096 바이트를 넘는 출력을 하면 부모가 할당해 준 버퍼가 꽉 차게 돼 이후 여유 버퍼가 생길 때까지 기다리게 되고, 반대로 서버 측은 그것을 읽지 않아서 버퍼가 가득 찬 상태로 계속 자식 프로세스가 종료하기를 기다리게 되는 것입니다.
이 문제를 해결하려면, 부모 측에서 WaitForExit에 앞서 Read 동작을 수행해 주면 됩니다.
Process? process = Process.Start(psi);
if (process != null)
{
string result = process.StandardOutput.ReadToEnd();
Console.WriteLine(result);
if (process.ExitCode != 0)
{
Console.WriteLine($"# ExitCode: {process.ExitCode}");
return;
}
}
ReadToEnd는 프로세스가 종료될 때까지 출력을 읽어들이기 때문에 저런 경우 굳이 WaitForExit를 호출하지 않아도 됩니다.
그런데, 가끔은 자식 프로세스의 종료를 특정하고 싶을 때가 있습니다. 가령, 3초 이상 걸린다면 그냥 읽기를 포기하는 것입니다. 그런데, 위와 같이 처리하는 경우에는 그것이 안 됩니다. 재현을 위해 자식 프로세스에 다음과 같이 코드를 추가하면,
internal class Program
{
static void Main(string[] args)
{
string text = new string('a', 1024 * 3 + 1024 + 1);
Console.Write(text);
Thread.Sleep(-1);
}
}
이후 부모 프로세스는 ReadToEnd에서 무한 대기를 하게 됩니다. 아쉽게도 만료 시간을 지정할 수 있었던 WaitForExit와는 달리 ReadToEnd는 그게 없는 건데요, 검색해 보면 BeginOutputReadLine을 곁들이면 된다고 나옵니다.
Process.BeginOutputReadLine Method
; https://learn.microsoft.com/en-us/dotnet/api/system.diagnostics.process.beginoutputreadline
위의 문서에 나온 예제대로 코드를 작성해,
Process? process = Process.Start(psi);
if (process != null)
{
StringBuilder sb = new StringBuilder();
process.OutputDataReceived += (sender, args) =>
{
sb.Append(args.Data);
};
process.BeginOutputReadLine();
TimeSpan waitTime = TimeSpan.FromSeconds(3);
if (process.WaitForExit((int)waitTime.TotalMilliseconds) == false)
{
Console.WriteLine($"# Output: {sb}"); // 언제나 sb == 빈 문자열
return;
}
Console.Write($"# Output: {sb}"); // 언제나 sb == 빈 문자열
if (process.HasExited == true && process.ExitCode != 0)
{
Console.WriteLine($"# ExitCode: {process.ExitCode}");
return;
}
}
실제로 실행해 보면, 자식 프로세스가 timeout이든 아니든 출력은 "# Output: "만 나옵니다. 가만 보니까, OutputDataReceived 이벤트 핸들러는 timeout이 아닌 경우, 즉 정상 출력을 마치고 종료한 경우에만 실행이 되었는데요, 그 실행 시점이 이상합니다. 즉, 실행 중에 이벤트 핸들러가 불리지 않고 (이후 부모 프로세스 측에서) "Console.Write"를 호출한 시점에 불리는데요, 아쉽게도 sb.ToString 평가는 그전에 끝나서 결과를 반영하지 못합니다. 이 문제를 해결하려면 더미로 그전에 Console.Write('\0')와 같은 호출을 하나 넣어주면 되는데, 테스트해 보니까 Console.Out.Flush를 해도 실행은 되므로 다음과 같이 코드를 보완할 수 있습니다.
TimeSpan waitTime = TimeSpan.FromSeconds(3);
if (process.WaitForExit((int)waitTime.TotalMilliseconds) == false)
{
Console.WriteLine($"# Output: {sb}"); // 언제나 sb == 빈 문자열
return;
}
Console.Out.Flush(); // 이 코드를 호출하는 순간 OutputDataReceived 콜백 발생
Console.Write($"# Output: {sb}"); // 자식 프로세스가 출력한 내용
그래도 timeout이 발생한 경우의 출력은 받아오지 못합니다. 하지만, 그렇다고 해서 자식 프로세스로부터 출력을 받지 못한 것은 아닙니다. 만약, 받지 못했다면 자식 프로세스는 Thread.Sleep(-1) 호출이 아닌 Console.Write(4096 + 1) 코드에서 멈췄을 것입니다.
실제로, Visual Studio를 이용해 디버거로 확인해 보면, Process 타입에 .NET Framework의 경우 output, .NET Core/5+의 경우 _output이라는 System.Diagnostics.AsyncStreamReader 타입의 필드가 있고,
/System/services/monitoring/system/diagnosticts/AsyncStreamReader.cs
; https://github.com/microsoft/referencesource/blob/master/System/services/monitoring/system/diagnosticts/AsyncStreamReader.cs
이 저장소에는 자식 프로세스가 그 시점까지 출력했던 내용이 담겨 있습니다. 따라서, Reflection을 사용한다면 이런 식으로 값을 가져올 수는 있습니다.
TimeSpan waitTime = TimeSpan.FromSeconds(3);
if (process.WaitForExit((int)waitTime.TotalMilliseconds) == false)
{
Console.WriteLine($"# Timeout: {waitTime}");
// .NET Framework
// string text = ReadAsyncStreamReader(process, "output", "sb");
// .NET Core/5+
string text = ReadAsyncStreamReader(process, "_output", "_sb");
Console.WriteLine($"# Output: {text}");
return;
}
private static string ReadAsyncStreamReader(Process process, string outputFieldName, string sbFieldName)
{
FieldInfo fi = typeof(Process).GetField(outputFieldName, System.Reflection.BindingFlags.NonPublic | System.Reflection.BindingFlags.Instance);
if (fi == null)
{
return "";
}
object objOutput = fi.GetValue(process);
if (objOutput == null)
{
return "";
}
fi = objOutput.GetType().GetField(sbFieldName, BindingFlags.NonPublic | BindingFlags.Instance);
if (fi == null)
{
return "";
}
object objText = fi.GetValue(objOutput);
if (objText == null)
{
return "";
}
return objText.ToString();
}
만약 .NET Core 2.1 이상을 사용하고 있다면, 다행히 더 좋은 방법이 있습니다. 바로 StandardOutput.ReadAsync 비동기 메서드를 사용하는 것인데요, 그럼 이렇게 코드를 만들 수 있습니다.
static async Task Main(string[] args)
{
ProcessStartInfo psi = new ProcessStartInfo();
psi.FileName = "ConsoleApp2.exe";
psi.RedirectStandardOutput = true;
Process? process = Process.Start(psi);
if (process != null)
{
try
{
StringBuilder sb = new StringBuilder();
Memory<char> buffer = new Memory<char>(new char[4096]);
CancellationTokenSource cts = new CancellationTokenSource();
cts.CancelAfter(TimeSpan.FromSeconds(3));
while (true)
{
try
{
int readBytes = await process.StandardOutput.ReadAsync(buffer, cts.Token);
if (readBytes == 0)
{
break;
}
}
catch
{
break;
}
sb.Append(buffer.ToString());
}
Console.Write($"# Output: {sb}");
if (process.HasExited && process.ExitCode != 0)
{
Console.WriteLine($"# ExitCode: {process.ExitCode}");
return;
}
}
finally
{
process.Dispose();
}
}
}
위의 경우, 자식 프로세스 실행 시 timeout이든 아니든 그에 상관없이 ReadAsync를 호출해 받아온 출력까지는 모두 구할 수 있습니다.
(
첨부 파일은 이 글의 예제 코드를 포함합니다.)
[이 글에 대해서 여러분들과 의견을 공유하고 싶습니다. 틀리거나 미흡한 부분 또는 의문 사항이 있으시면 언제든 댓글 남겨주십시오.]