Fix garbled PF_ConsoleLogs.txt when collecting Linux container logs

VmAgent.Core.UnitTests/DockerContainerEngineTests.cs

@@ -10,8 +10,12 @@
 using Microsoft.Azure.Gaming.AgentInterfaces;
 using Microsoft.Extensions.Logging.Abstractions;
 using Moq;
+using System;
 using System.Collections.Generic;
+using System.IO;
 using System.Runtime.InteropServices;
+using System.Text;
+using System.Threading.Tasks;
 
 namespace VmAgent.Core.UnitTests
 {
@@ -172,5 +176,91 @@ public void GetGameWorkingDir_LinuxHost_ShouldReturnNull()
 
             Assert.IsNull(result);
         }
+
+        [TestMethod]
+        [TestCategory("BVT")]
+        public async Task DemuxDockerStream_SingleStdoutFrame_ExtractsContent()
+        {
+            string logLine = "BASH=/bin/bash\n";
+            byte[] payload = Encoding.UTF8.GetBytes(logLine);
+            byte[] frame = CreateDockerStreamFrame(1, payload); // 1 = stdout
+
+            using var stream = new MemoryStream(frame);
+            var output = new StringBuilder();
+
+            await DockerContainerEngine.DemuxDockerStream(stream, content => output.Append(content));
+
+            Assert.AreEqual(logLine, output.ToString());
+        }
+
+        [TestMethod]
+        [TestCategory("BVT")]
+        public async Task DemuxDockerStream_MultipleFrames_ExtractsAllContent()
+        {
+            string line1 = "BASH=/bin/bash\n";
+            string line2 = "HOME=/root\n";
+            byte[] frame1 = CreateDockerStreamFrame(1, Encoding.UTF8.GetBytes(line1));
+            byte[] frame2 = CreateDockerStreamFrame(2, Encoding.UTF8.GetBytes(line2)); // 2 = stderr
+
+            byte[] combined = new byte[frame1.Length + frame2.Length];
+            Buffer.BlockCopy(frame1, 0, combined, 0, frame1.Length);
+            Buffer.BlockCopy(frame2, 0, combined, frame1.Length, frame2.Length);
+
+            using var stream = new MemoryStream(combined);
+            var output = new StringBuilder();
+
+            await DockerContainerEngine.DemuxDockerStream(stream, content => output.Append(content));
+
+            Assert.AreEqual(line1 + line2, output.ToString());
+        }
+
+        [TestMethod]
+        [TestCategory("BVT")]
+        public async Task DemuxDockerStream_EmptyStream_ProducesNoOutput()
+        {
+            using var stream = new MemoryStream(Array.Empty<byte>());
+            var output = new StringBuilder();
+
+            await DockerContainerEngine.DemuxDockerStream(stream, content => output.Append(content));
+
+            Assert.AreEqual(string.Empty, output.ToString());
+        }
+
+        [TestMethod]
+        [TestCategory("BVT")]
+        public async Task DemuxDockerStream_ZeroLengthPayload_SkipsFrame()
+        {
+            string logLine = "actual content\n";
+            byte[] emptyFrame = CreateDockerStreamFrame(1, Array.Empty<byte>());
+            byte[] contentFrame = CreateDockerStreamFrame(1, Encoding.UTF8.GetBytes(logLine));
+
+            byte[] combined = new byte[emptyFrame.Length + contentFrame.Length];
+            Buffer.BlockCopy(emptyFrame, 0, combined, 0, emptyFrame.Length);
+            Buffer.BlockCopy(contentFrame, 0, combined, emptyFrame.Length, contentFrame.Length);
+
+            using var stream = new MemoryStream(combined);
+            var output = new StringBuilder();
+
+            await DockerContainerEngine.DemuxDockerStream(stream, content => output.Append(content));
+
+            Assert.AreEqual(logLine, output.ToString());
+        }
+
+        /// <summary>
+        /// Creates a Docker multiplexed stream frame with the standard 8-byte header.
+        /// </summary>
+        private static byte[] CreateDockerStreamFrame(byte streamType, byte[] payload)
+        {
+            byte[] frame = new byte[8 + payload.Length];
+            frame[0] = streamType;
+            // bytes 1-3 are padding (zeros)
+            // bytes 4-7 are payload size as big-endian uint32
+            frame[4] = (byte)((payload.Length >> 24) & 0xFF);
+            frame[5] = (byte)((payload.Length >> 16) & 0xFF);
+            frame[6] = (byte)((payload.Length >> 8) & 0xFF);
+            frame[7] = (byte)(payload.Length & 0xFF);
+            Buffer.BlockCopy(payload, 0, frame, 8, payload.Length);
+            return frame;
+        }
     }
 }

VmAgent.Core/Interfaces/DockerContainerEngine.cs

@@ -509,22 +509,21 @@
                     // we do this for lcow since containers are running on a Hyper-V Linux machine
                     // which the host Windows machine does not have "copy" access to, to get the logs with a FileCopy
                     // this is only supposed to run on LocalMultiplayerAgent running on lcow
-                    StringBuilder sb = new StringBuilder();
                     Stream logsStream = await _dockerClient.Containers.GetContainerLogsAsync(containerId,
                         new ContainerLogsParameters() {ShowStdout = true, ShowStderr = true});
-                    using (StreamReader sr = new StreamReader(logsStream))
+
+                    Stopwatch sw = new Stopwatch();
+                    sw.Start();
+                    await DemuxDockerStream(logsStream, (content) =>
                     {
-                        Stopwatch sw = new Stopwatch();
-                        while (!sr.EndOfStream)
+                        if (sw.Elapsed.TotalSeconds > 3) // don't flood STDOUT with messages, output one every 3 seconds if logs are too many
                         {
-                            if (sw.Elapsed.Seconds > 3) // don't flood STDOUT with messages, output one every 3 seconds if logs are too many
-                            {
-                                _logger.LogVerbose($"Gathering logs for container {containerId}, please wait...");
-                                sw.Restart();
-                            }
-                            _systemOperations.FileAppendAllText(destinationFileName, sr.ReadLine() + Environment.NewLine);
+                            _logger.LogVerbose($"Gathering logs for container {containerId}, please wait...");
+                            sw.Restart();
                         }
-                    }
+                        _systemOperations.FileAppendAllText(destinationFileName, content);
+                    });
+
                     _logger.LogVerbose($"Written logs for container {containerId} to {destinationFileName}.");
                 }
                 else
@@ -544,6 +543,60 @@
             }
         }
 
+        /// <summary>
+        /// Reads a Docker multiplexed stream and extracts the log content, stripping the 8-byte binary headers.
+        /// Docker uses a multiplexed stream format for container logs when TTY is not enabled:
+        /// - Bytes 0: stream type (1=stdout, 2=stderr)
+        /// - Bytes 1-3: padding (zeros)
+        /// - Bytes 4-7: payload size as big-endian uint32
+        /// - Followed by payload bytes of the specified size
+        /// </summary>
+        internal static async Task DemuxDockerStream(Stream multiplexedStream, Action<string> writeContent)
+        {
+            byte[] header = new byte[8];
+            while (true)
+            {
+                int headerBytesRead = await ReadExactAsync(multiplexedStream, header, 0, 8);
+                if (headerBytesRead < 8)
+                {
+                    break;
+                }
+
+                int payloadSize = (header[4] << 24) | (header[5] << 16) | (header[6] << 8) | header[7];
+
+                if (payloadSize == 0)
+                {
+                    continue;
+                }
+
+                byte[] payload = new byte[payloadSize];
+                int payloadBytesRead = await ReadExactAsync(multiplexedStream, payload, 0, payloadSize);
+
+                string content = Encoding.UTF8.GetString(payload, 0, payloadBytesRead);
+                writeContent(content);
+
+                if (payloadBytesRead < payloadSize)
+                {
+                    break;
+                }
+            }
+        }
+
+        private static async Task<int> ReadExactAsync(Stream stream, byte[] buffer, int offset, int count)
+        {
+            int totalRead = 0;
+            while (totalRead < count)
+            {
+                int bytesRead = await stream.ReadAsync(buffer, offset + totalRead, count - totalRead);
+                if (bytesRead == 0)
+                {
+                    break;
+                }
+                totalRead += bytesRead;
+            }
+            return totalRead;
+        }
+
         public override async Task<bool> TryDelete(string id)
         {
             bool result = true;