From eebf3792cd8bb0171990c868a6c8488bdfe7ff92 Mon Sep 17 00:00:00 2001
From: Jordan Brown <Cyberboss@users.noreply.github.com>
Date: Tue, 10 Aug 2021 15:22:01 -0400
Subject: [PATCH] Additional logging around process stream reading

---
 src/Tgstation.Server.Host/System/Process.cs     | 17 ++++++++++++-----
 .../System/ProcessExecutor.cs                   | 12 +++++++++---
 2 files changed, 21 insertions(+), 8 deletions(-)

diff --git a/src/Tgstation.Server.Host/System/Process.cs b/src/Tgstation.Server.Host/System/Process.cs
index a3bc854915..2ff8ccf1b4 100644
--- a/src/Tgstation.Server.Host/System/Process.cs
+++ b/src/Tgstation.Server.Host/System/Process.cs
@@ -134,24 +134,31 @@ namespace Tgstation.Server.Host.System
 		{
 			if (combinedStringBuilder == null)
 				throw new InvalidOperationException("Output/Error stream reading was not enabled!");
-			await Task.WhenAll(standardOutputTask, standardErrorTask).WithToken(cancellationToken).ConfigureAwait(false);
+			await Task.WhenAll(
+				GetStandardOutput(cancellationToken),
+				GetErrorOutput(cancellationToken))
+				.ConfigureAwait(false);
 			return combinedStringBuilder.ToString().TrimStart(Environment.NewLine.ToCharArray());
 		}
 
 		/// <inheritdoc />
-		public Task<string> GetErrorOutput(CancellationToken cancellationToken)
+		public async Task<string> GetErrorOutput(CancellationToken cancellationToken)
 		{
 			if (standardErrorTask == null)
 				throw new InvalidOperationException("Error stream reading was not enabled!");
-			return standardErrorTask.WithToken(cancellationToken);
+			if (!standardErrorTask.IsCompleted)
+				logger.LogTrace("Waiting for PID {0} to close error stream...", Id);
+			return await standardErrorTask.WithToken(cancellationToken).ConfigureAwait(false);
 		}
 
 		/// <inheritdoc />
-		public Task<string> GetStandardOutput(CancellationToken cancellationToken)
+		public async Task<string> GetStandardOutput(CancellationToken cancellationToken)
 		{
 			if (standardOutputTask == null)
 				throw new InvalidOperationException("Output stream reading was not enabled!");
-			return standardOutputTask.WithToken(cancellationToken);
+			if (!standardOutputTask.IsCompleted)
+				logger.LogTrace("Waiting for PID {0} to close output stream...", Id);
+			return await standardOutputTask.WithToken(cancellationToken).ConfigureAwait(false);
 		}
 
 		/// <inheritdoc />
diff --git a/src/Tgstation.Server.Host/System/ProcessExecutor.cs b/src/Tgstation.Server.Host/System/ProcessExecutor.cs
index 907d056e26..17e0d18d9f 100644
--- a/src/Tgstation.Server.Host/System/ProcessExecutor.cs
+++ b/src/Tgstation.Server.Host/System/ProcessExecutor.cs
@@ -176,13 +176,17 @@ namespace Tgstation.Server.Host.System
 				{
 					combinedStringBuilder = new StringBuilder();
 
-					async Task<string> ConsumeReader(Func<TextReader> readerFunc)
+					async Task<string> ConsumeReader(Func<TextReader> readerFunc, bool isOutputStream)
 					{
 						var stringBuilder = new StringBuilder();
 						string text;
 
 						await processStartTcs.Task.ConfigureAwait(false);
 
+						var pid = handle.Id;
+						var streamType = isOutputStream ? "out" : "err";
+						logger.LogTrace("Starting std{0} read for PID {1}...", streamType, pid);
+
 						var reader = readerFunc();
 						while ((text = await reader.ReadLineAsync().ConfigureAwait(false)) != null)
 						{
@@ -192,18 +196,20 @@ namespace Tgstation.Server.Host.System
 							stringBuilder.Append(text);
 						}
 
+						logger.LogTrace("Finished std{0} read for PID {1}", streamType, pid);
+
 						return stringBuilder.ToString();
 					}
 
 					if (readOutput)
 					{
-						outputTask = ConsumeReader(() => handle.StandardOutput);
+						outputTask = ConsumeReader(() => handle.StandardOutput, true);
 						handle.StartInfo.RedirectStandardOutput = true;
 					}
 
 					if (readError)
 					{
-						errorTask = ConsumeReader(() => handle.StandardError);
+						errorTask = ConsumeReader(() => handle.StandardError, false);
 						handle.StartInfo.RedirectStandardError = true;
 					}
 				}