Merge branch 'dev' of https://git-codecommit.us-west-2.amazonaws.com/v1/repos/aws-lambda-dotnet

Author: normj

Libraries/src/Amazon.Lambda.RuntimeSupport/Amazon.Lambda.RuntimeSupport.csproj

@@ -4,9 +4,9 @@
 
   <PropertyGroup>
     <TargetFrameworks>netstandard2.0;net5.0;net6.0</TargetFrameworks>
-    <VersionPrefix>1.8.1</VersionPrefix>
+    <VersionPrefix>1.8.2</VersionPrefix>
     <Description>Provides a bootstrap and Lambda Runtime API Client to help you to develop custom .NET Core Lambda Runtimes.</Description>
-    <VersionPrefix>1.8.1</VersionPrefix>
+    <VersionPrefix>1.8.2</VersionPrefix>
     <Description>Provides a bootstrap and Lambda Runtime API Client to help you  to develop custom .NET Core Lambda Runtimes.</Description>
     <AssemblyTitle>Amazon.Lambda.RuntimeSupport</AssemblyTitle>
     <AssemblyName>Amazon.Lambda.RuntimeSupport</AssemblyName>

Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/FileDescriptorLogStream.cs

@@ -15,17 +15,41 @@ public static class FileDescriptorLogFactory
     {
         private readonly static ConcurrentDictionary<string, StreamWriter> _writers = new ConcurrentDictionary<string, StreamWriter>();
 
+        // max cloudwatch log event size, 256k - 26 bytes of overhead.
+        internal const int MaxCloudWatchLogEventSize = 256 * 1024 - 26;
+        internal const int LambdaTelemetryLogHeaderLength = 8;
+        internal const uint LambdaTelemetryLogHeaderFrameType = 0xa55a0001;
+
         /// <summary>
         /// Get the StreamWriter for the particular file descriptor ID. If the same ID is passed the same StreamWriter instance is returned.
         /// </summary>
         /// <param name="fileDescriptorId"></param>
         /// <returns></returns>
         public static StreamWriter GetWriter(string fileDescriptorId)
+        {
+            var writer = _writers.GetOrAdd(fileDescriptorId, 
+                (x) => {
+                    SafeFileHandle handle = new SafeFileHandle(new IntPtr(int.Parse(fileDescriptorId)), false);
+                    return InitializeWriter(new FileStream(handle, FileAccess.Write));
+                });
+            return writer;
+        }
+
+        /// <summary>
+        /// Initialize a StreamWriter for the given Stream.
+        /// This method is internal as it is tested in Amazon.RuntimeSupport.Tests
+        /// </summary>
+        /// <param name="fileDescriptorStream"></param>
+        /// <returns></returns>
+        internal static StreamWriter InitializeWriter(Stream fileDescriptorStream)
         {
             // AutoFlush must be turned out otherwise the StreamWriter might not send the data to the stream before the Lambda function completes.
             // Set the buffer size to the same max size as CloudWatch Logs records.
-            var writer = _writers.GetOrAdd(fileDescriptorId, (x) => new StreamWriter(new FileDescriptorLogStream(fileDescriptorId), Encoding.UTF8, 256 * 1024) { AutoFlush = true });
-            return writer;
+            // Encoder has encoderShouldEmitUTF8Identifier = false as Lambda FD will assume UTF-8 so there is no need to emit an extra log entry.
+            // In fact this extra log entry is cast to UTF-8 and results in an empty log entry which will be rejected by CloudWatch Logs.
+            return new StreamWriter(new FileDescriptorLogStream(fileDescriptorStream),
+                    new UTF8Encoding(false), MaxCloudWatchLogEventSize)
+                { AutoFlush = true };
         }
 
         /// <summary>
@@ -40,16 +64,14 @@ public static StreamWriter GetWriter(string fileDescriptorId)
         /// </summary>
         private class FileDescriptorLogStream : Stream
         {
-            private const uint FRAME_TYPE = 0xa55a0001;
             private readonly Stream _fileDescriptorStream;
             private readonly byte[] _frameTypeBytes;
 
-            public FileDescriptorLogStream(string fileDescriptorId)
+            public FileDescriptorLogStream(Stream logStream)
             {
-                SafeFileHandle handle = new SafeFileHandle(new IntPtr(int.Parse(fileDescriptorId)), false);
-                _fileDescriptorStream = new FileStream(handle, FileAccess.Write);
+                _fileDescriptorStream = logStream;
 
-                _frameTypeBytes = BitConverter.GetBytes(FRAME_TYPE);
+                _frameTypeBytes = BitConverter.GetBytes(LambdaTelemetryLogHeaderFrameType);
                 if (BitConverter.IsLittleEndian)
                 {
                     Array.Reverse(_frameTypeBytes);
@@ -69,7 +91,7 @@ public override void Write(byte[] buffer, int offset, int count)
                     Array.Reverse(messageLengthBytes);
                 }
 
-                var typeAndLength = ArrayPool<byte>.Shared.Rent(8);
+                var typeAndLength = ArrayPool<byte>.Shared.Rent(LambdaTelemetryLogHeaderLength);
                 try
                 {
                     Buffer.BlockCopy(_frameTypeBytes, 0, typeAndLength, 0, 4);
@@ -113,4 +135,4 @@ public override void SetLength(long value)
             #endregion
         }
     }
-}
+}

Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/FileDescriptorLogStreamTests.cs

@@ -0,0 +1,193 @@
+using System;
+using System.Collections.Generic;
+using System.IO;
+using System.Linq;
+using System.Text;
+using Amazon.Lambda.RuntimeSupport.Helpers;
+using Amazon.Lambda.RuntimeSupport.UnitTests.TestHelpers;
+using Xunit;
+
+namespace Amazon.Lambda.RuntimeSupport.UnitTests
+{
+    public class FileDescriptorLogStreamTests
+    {
+        private const int HeaderLength = FileDescriptorLogFactory.LambdaTelemetryLogHeaderLength;
+        private const int LogEntryMaxLength = FileDescriptorLogFactory.MaxCloudWatchLogEventSize;
+
+        private static readonly byte[] ExpectedMagicBytes =
+        {
+            0xA5, 0x5A, 0x00, 0x01
+        };
+
+        [Fact]
+        public void MultilineLoggingInSingleLogEntryWithTlvFormat()
+        {
+            var logs = new List<byte[]>();
+            var offsets = new List<int>();
+            var counts = new List<int>();
+            var stream = new TestFileStream((log, offset, count) =>
+            {
+                logs.Add(log);
+                offsets.Add(offset);
+                counts.Add(count);
+            });
+            TextWriter writer = FileDescriptorLogFactory.InitializeWriter(stream);
+            // assert that initializing the stream does not result in UTF-8 preamble log entry
+            Assert.Equal(0, counts.Count);
+            Assert.Equal(0, offsets.Count);
+            Assert.Equal(0, logs.Count);
+
+            const string logMessage = "hello world\nsomething else on a new line.";
+            int logMessageLength = logMessage.Length;
+            writer.Write(logMessage);
+
+            Assert.Equal(2, offsets.Count);
+            int headerLogEntryOffset = offsets[0];
+            int consoleLogEntryOffset = offsets[1];
+            Assert.Equal(0, headerLogEntryOffset);
+            Assert.Equal(0, consoleLogEntryOffset);
+
+            Assert.Equal(2, counts.Count);
+            int headerLogEntrySize = counts[0];
+            int consoleLogEntrySize = counts[1];
+            Assert.Equal(HeaderLength, headerLogEntrySize);
+            Assert.Equal(logMessageLength, consoleLogEntrySize);
+
+            Assert.Equal(2, logs.Count);
+            byte[] headerLogEntry = logs[0];
+            byte[] consoleLogEntry = logs[1];
+            Assert.Equal(HeaderLength, headerLogEntry.Length);
+            Assert.Equal(logMessageLength, consoleLogEntry.Length);
+
+            byte[] expectedLengthBytes =
+            {
+                0x00, 0x00, 0x00, 0x29
+            };
+            AssertHeaderBytes(headerLogEntry, expectedLengthBytes);
+            Assert.Equal(logMessage, Encoding.UTF8.GetString(consoleLogEntry));
+        }
+
+        [Fact]
+        public void MaxSizeProducesOneLogFrame()
+        {
+            var logs = new List<byte[]>();
+            var offsets = new List<int>();
+            var counts = new List<int>();
+            var stream = new TestFileStream((log, offset, count) =>
+            {
+                logs.Add(log);
+                offsets.Add(offset);
+                counts.Add(count);
+            });
+            TextWriter writer = FileDescriptorLogFactory.InitializeWriter(stream);
+            // assert that initializing the stream does not result in UTF-8 preamble log entry
+            Assert.Equal(0, counts.Count);
+            Assert.Equal(0, offsets.Count);
+            Assert.Equal(0, logs.Count);
+
+            string logMessage = new string('a', LogEntryMaxLength - 1) + "b";
+            writer.Write(logMessage);
+
+            Assert.Equal(2, offsets.Count);
+            int headerLogEntryOffset = offsets[0];
+            int consoleLogEntryOffset = offsets[1];
+            Assert.Equal(0, headerLogEntryOffset);
+            Assert.Equal(0, consoleLogEntryOffset);
+
+            Assert.Equal(2, counts.Count);
+            int headerLogEntrySize = counts[0];
+            int consoleLogEntrySize = counts[1];
+            Assert.Equal(HeaderLength, headerLogEntrySize);
+            Assert.Equal(LogEntryMaxLength, consoleLogEntrySize);
+
+            Assert.Equal(2, logs.Count);
+            byte[] headerLogEntry = logs[0];
+            byte[] consoleLogEntry = logs[1];
+            Assert.Equal(HeaderLength, headerLogEntry.Length);
+            Assert.Equal(LogEntryMaxLength, consoleLogEntry.Length);
+
+            byte[] expectedLengthBytes =
+            {
+                0x00, 0x03, 0xFF, 0xE6
+            };
+            AssertHeaderBytes(headerLogEntry, expectedLengthBytes);
+            Assert.Equal(logMessage, Encoding.UTF8.GetString(consoleLogEntry));
+        }
+
+        [Fact]
+        public void LogEntryAboveMaxSizeProducesMultipleLogFrames()
+        {
+            var logs = new List<byte[]>();
+            var offsets = new List<int>();
+            var counts = new List<int>();
+            var stream = new TestFileStream((log, offset, count) =>
+            {
+                logs.Add(log);
+                offsets.Add(offset);
+                counts.Add(count);
+            });
+            TextWriter writer = FileDescriptorLogFactory.InitializeWriter(stream);
+            // assert that initializing the stream does not result in UTF-8 preamble log entry
+            Assert.Equal(0, counts.Count);
+            Assert.Equal(0, offsets.Count);
+            Assert.Equal(0, logs.Count);
+
+            string logMessage = new string('a', LogEntryMaxLength) + "b";
+            writer.Write(logMessage);
+
+            Assert.Equal(4, offsets.Count);
+            int headerLogEntryOffset = offsets[0];
+            int consoleLogEntryOffset = offsets[1];
+            int headerLogSecondEntryOffset = offsets[2];
+            int consoleLogSecondEntryOffset = offsets[3];
+            Assert.Equal(0, headerLogEntryOffset);
+            Assert.Equal(0, consoleLogEntryOffset);
+            Assert.Equal(0, headerLogSecondEntryOffset);
+            Assert.Equal(0, consoleLogSecondEntryOffset);
+
+            Assert.Equal(4, counts.Count);
+            int headerLogEntrySize = counts[0];
+            int consoleLogEntrySize = counts[1];
+            int headerLogSecondEntrySize = counts[2];
+            int consoleLogSecondEntrySize = counts[3];
+            Assert.Equal(HeaderLength, headerLogEntrySize);
+            Assert.Equal(LogEntryMaxLength, consoleLogEntrySize);
+            Assert.Equal(HeaderLength, headerLogSecondEntrySize);
+            Assert.Equal(1, consoleLogSecondEntrySize);
+
+            Assert.Equal(4, logs.Count);
+            byte[] headerLogEntry = logs[0];
+            byte[] consoleLogEntry = logs[1];
+            byte[] headerLogSecondEntry = logs[2];
+            byte[] consoleLogSecondEntry = logs[3];
+            Assert.Equal(HeaderLength, headerLogEntry.Length);
+            Assert.Equal(LogEntryMaxLength, consoleLogEntry.Length);
+            Assert.Equal(HeaderLength, headerLogSecondEntry.Length);
+            Assert.Equal(1, consoleLogSecondEntry.Length);
+
+            byte[] expectedLengthBytes =
+            {
+                0x00, 0x03, 0xFF, 0xE6
+            };
+            AssertHeaderBytes(headerLogEntry, expectedLengthBytes);
+
+            byte[] expectedLengthBytesSecondEntry =
+            {
+                0x00, 0x00, 0x00, 0x01
+            };
+            AssertHeaderBytes(headerLogSecondEntry, expectedLengthBytesSecondEntry);
+            string expectedLogEntry = logMessage.Substring(0, LogEntryMaxLength);
+            string expectedSecondLogEntry = logMessage.Substring(LogEntryMaxLength);
+            Assert.Equal(expectedLogEntry, Encoding.UTF8.GetString(consoleLogEntry));
+            Assert.Equal(expectedSecondLogEntry, Encoding.UTF8.GetString(consoleLogSecondEntry));
+        }
+
+        private static void AssertHeaderBytes(byte[] buf, byte[] expectedLengthBytes)
+        {
+            byte[] actualHeaderMagicBytes = buf.Take(4).ToArray();
+            byte[] actualHeaderLengthBytes = buf.TakeLast(4).ToArray();
+            Assert.Equal(ExpectedMagicBytes, actualHeaderMagicBytes);
+            Assert.Equal(expectedLengthBytes, actualHeaderLengthBytes);
+        }
+    }
+}

Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/TestHelpers/TestFileStream.cs

@@ -0,0 +1,31 @@
+using System;
+using System.Collections.Generic;
+using System.IO;
+using System.Linq;
+
+namespace Amazon.Lambda.RuntimeSupport.UnitTests.TestHelpers
+{
+    public class TestFileStream : FileStream
+    {
+        private Action<byte[], int, int> WriteAction { get; }
+
+        public TestFileStream(Action<byte[], int, int> writeAction)
+            : base(Path.GetTempFileName(), FileMode.Append, FileAccess.Write)
+        {
+            WriteAction = writeAction;
+        }
+
+        public override bool CanWrite => true;
+
+        public override void Write(byte[] buffer, int offset, int count)
+        {
+            WriteAction(TrimTrailingNullBytes(buffer).Take(count).ToArray(), offset, count);
+        }
+
+        private static IEnumerable<byte> TrimTrailingNullBytes(IEnumerable<byte> buffer)
+        {
+            // Trim trailing null bytes to make testing assertions easier
+            return buffer.Reverse().SkipWhile(x => x == 0).Reverse();
+        }
+    }
+}