aws-lambda-dotnet icon indicating copy to clipboard operation
aws-lambda-dotnet copied to clipboard

Lambda multiline logging messages - different behaviour between Zip & Image (docker) package type

Open TibbsTerry opened this issue 1 year ago • 3 comments

Describe the bug

Simple Lambda function with Console.WriteLine statements will behave differently for Zip & image (docker) packages

Console logging of a multi-line statement eg: Console.WriteLine("Multi line example" + Environment.NewLine + "Multi line example"); will appear as one CloudWatch entry when deployed using a zip file but will appear as two CloudWatch entries in a docker runtime

This is also an issue using logging providers such as Microsoft.Extensions.Logging.Console & Amazon.Lambda.Logging.AspNetCore. (probably because they all use Amazon.Lambda.Core.LambdaLogger?)

Expected Behavior

One logging message should be written to one CloudWatch entry. Behaviour should be consistent.

Current Behavior

Behaviour is not consistent. There is one CloudWatch entry when deployed using a zip file but two CloudWatch entries in a docker runtime.

Reproduction Steps

Simple lambda function:

public class Function 
{
    public void FunctionHandler(ILambdaContext context)
    {
        Console.WriteLine($"** Func Start v{ThisAssembly.Info.Version}**");

        Console.WriteLine("Single line console example");

        Console.WriteLine("Multi line console example" + Environment.NewLine + "Multi line console example");
    }
}
<Project Sdk="Microsoft.NET.Sdk">
  <PropertyGroup>
    <TargetFramework>net6.0</TargetFramework>
    <ImplicitUsings>enable</ImplicitUsings>
    <Nullable>enable</Nullable>
    <GenerateRuntimeConfigurationFiles>true</GenerateRuntimeConfigurationFiles>
    <AWSProjectType>Lambda</AWSProjectType>
    <CopyLocalLockFileAssemblies>true</CopyLocalLockFileAssemblies>
    <PublishReadyToRun>true</PublishReadyToRun>
	  <BuildCounter Condition="'$(BuildCounter)' == ''">$([System.DateTime]::Now.ToString('HHmm'))</BuildCounter>
	  <VersionPrefix>1.0.$(BuildCounter)</VersionPrefix>
  </PropertyGroup>
	<ItemGroup>
		<PackageReference Include="Amazon.Lambda.Serialization.SystemTextJson" Version="2.4.0" />
		<PackageReference Include="ThisAssembly" Version="1.4.1">
			<PrivateAssets>all</PrivateAssets>
			<IncludeAssets>runtime; build; native; contentfiles; analyzers; buildtransitive</IncludeAssets>
		</PackageReference>
	</ItemGroup>
</Project>

Zip deployment:

{
  "profile": "*****",
  "region": "******",
  "configuration": "Release",
  "function-architecture": "x86_64",
  "function-runtime": "dotnet6",
  "function-memory-size": 256,
  "function-timeout": 30,
  "function-handler": "LambdaLoggingZip::LambdaLoggingZip.Function::FunctionHandler"
}

Docker deployment:

FROM public.ecr.aws/lambda/dotnet:6 AS base

FROM mcr.microsoft.com/dotnet/sdk:6.0-bullseye-slim as build
WORKDIR /src
COPY ["LambdaLoggingTest.csproj", "LambdaLoggingTest/"]
RUN dotnet restore "LambdaLoggingTest/LambdaLoggingTest.csproj"

WORKDIR "/src/LambdaLoggingTest"
COPY . .
RUN dotnet build "LambdaLoggingTest.csproj" --configuration Release --output /app/build

FROM build AS publish
RUN dotnet publish "LambdaLoggingTest.csproj" \
            --configuration Release \ 
            --runtime linux-x64 \
            --self-contained false \ 
            --output /app/publish \
            -p:PublishReadyToRun=true  

FROM base AS final
WORKDIR /var/task
COPY --from=publish /app/publish .
CMD ["LambdaLoggingTest::LambdaLoggingTest.Function::FunctionHandler"] 
{
  "profile": "*************",
  "region": "***************",
  "configuration": "Release",
  "package-type": "image",
  "function-memory-size": 256,
  "function-timeout": 30,
  "image-command": "LambdaLoggingTest::LambdaLoggingTest.Function::FunctionHandler"
}

Possible Solution

Issue probably in Amazon.Lambda.Core.LambdaLogger ?

Additional Information/Context

No response

AWS .NET SDK and/or Package version used

Targeted .NET Platform

net6.0 / net7.0

Operating System and version

TibbsTerry avatar Jan 23 '24 02:01 TibbsTerry

Also an issue with the dotnet:7 runtime image

TibbsTerry avatar Jan 23 '24 04:01 TibbsTerry

This is a limitations with container based Lambda functions. For zip based Lambda functions the Lambda environment is given a special endpoint to send the logs to and we can send the log messages as your code sends them. But with container based images that special endpoint doesn't exist. Logs in containers is basically scrapping stdout and when doing that their is no context when a log message ends so newlines is used in the absence of anything better coming from stdout.

If you are curious from the .NET side here is the code in the .NET Lambda runtime client that chooses between the 2 different systems. https://github.com/aws/aws-lambda-dotnet/blob/master/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/ConsoleLoggerWriter.cs#L156

normj avatar Jan 24 '24 08:01 normj

I believe Amazon.Lambda.Logging.AspNetCore has the same issue?

https://github.com/aws/aws-lambda-dotnet/blob/a2421013def1e938d24b3e9f9c3453868d77a360/Libraries/src/Amazon.Lambda.Core/LambdaLogger.cs#L18

So we have to write our own custom ILoggerProvider if we want to use containers?? Seems a bit ridiculous?

TibbsTerry avatar Jan 25 '24 01:01 TibbsTerry

Any update on this issue?

TibbsTerry avatar Mar 06 '24 22:03 TibbsTerry

Lambda has no plans to change how containers are run to provide access to the separate telemetry API. Once we get structured logging support in place for .NET that will provide you a work around where the whole structured logging will be compressed into a single line with newlines being escaped.

I'm going to close this issue but if you want to track the structured logging support follow this PR. https://github.com/aws/aws-lambda-dotnet/pull/1588

normj avatar Mar 29 '24 21:03 normj

Comments on closed issues are hard for our team to see. If you need more assistance, please either tag a team member or open a new issue that references this one. If you wish to keep having a conversation with other community members under this issue feel free to do so.

github-actions[bot] avatar Mar 29 '24 21:03 github-actions[bot]