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

[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

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

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

[adrianiftode]

Is it safe to assume this is the expected behavior because of the following?

Background processes or callbacks initiated by your Lambda function that did not complete when the function ended resume if AWS Lambda chooses to reuse the execution context. You should make sure any background processes or callbacks in your code are complete before the code exits.

[adrianiftode]

I think this is more like an RTFM issue, than an issue with AWS Lambda, so I'm closing this one.

As per AWS Logging .NET docs

These packages batch logging messages in a queue and send messages to CloudWatch Logs using a background thread. The use of the background thread means that the messages are not guaranteed to be delivered when used in AWS Lambda. The reason is because the background thread will be frozen once a Lambda event is processed and may not ever be unfrozen if more Lambda events are not received for some time.

[darylleak]

Adrian did you ever solve this? Having the same issue and we need the logs as we have live dashboards connected. Happy to use other packages and be pointed in the right direction.

[adrianiftode]

This was not solved, and unfortunately, I am not involved anymore in that project. Any solution that does logging directly to CloudWatch would impact the app performances, so what I would advise here to log directly to Console, which in turn does logging to the native CloudWatch asynchronously and behind the scenes, by AWS. Then have an extra step the centralize the logs, by streaming them to a centralized location of your choice.