Skip to content

Logging with [AWS Logging .NET] or [Serilog Sink for AWS CloudWatch] suppresses some logging messages #571

@adrianiftode

Description

@adrianiftode

I have created the following repository to reproduce this scenario.

https://github.com/adrianiftode/SerilogSinksCloudWatchIssue

Not all logging messages are sent to CloudWatch, there are always some remaining messages in a pending queue.

Once you publish this to AWS Lambda do several requests on it, something like this

async void Main()
{
    var client = new HttpClient();
    
    foreach (var value in Enumerable.Range(1, 100))
    {
        await client.GetAsync($"https://{your-lambda}.execute-api.eu-west-1.amazonaws.com/Prod/api/values/{value}");
    }
    
    "ready".Dump();
}

We will see that not all messages are logged in none of the LogGroups we've set. The messages are logged in order, as expected, but there are always some of them that remain in pending.
Once a new Lambda request is made, then those remaining messages are processed, otherwise they are never sent to CloudWatch.

This issue happens with both most used sinks

Sink Configured LogGroup Name
AWS Logging .NET Serilog.AWS
Serilog Sink for AWS CloudWatch Serilog.Cimpress
Serilog Sink for AWS CloudWatch - Custom Sink Serilog.Cimpress.Custom

It looks like what goes in background processing is not completely executed.

The following code proves that PeriodicBatching is not working on AWS Lambda, the SelfLog does not log at every second so this might explain why some messages are not sent.

 internal class CloudWatchLogSinkWithLogging : CloudWatchLogSink
    {
        public CloudWatchLogSinkWithLogging(IAmazonCloudWatchLogs cloudWatchClient, ICloudWatchSinkOptions options) : base(cloudWatchClient, options)
        {
        }

        protected override async Task OnEmptyBatchAsync()
        {
            // this should be called at every second, but it doesn't happen on AWS Lambda
            // on the local machine it happens as expected

            // this proves the `PeriodicBatchingSink` does not work as expected on AWS Lambda

            SelfLog.WriteLine("OnEmptyBatchAsync");
            await base.OnEmptyBatchAsync();
        }

        protected override Task EmitBatchAsync(IEnumerable<LogEvent> events)
        {
            SelfLog.WriteLine("EmitBatchAsync - events to emit " + events?.Count());
            return base.EmitBatchAsync(events);
        }
    }

So for example this is the output on a local machine

Console

But if you open the Monitoring section from AWS Lambda you'll see OnEmptyBatchAsync logged once or twice.

The following two screenshots prove that not all messages appear in the log groups. Also, there are no new Log Streams

AWS Logging .NET
Serilog Sink for AWS CloudWatch
Serilog Sink for AWS CloudWatch Custom Sink

I'm trying to understand if any sort of background processing is simply forbidden in a Lambda environment and if we should go with Amazon.Lambda.Logging.AspNetCore only

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions