Some AWS lambda logs go missing

[rowanmanning]

Sometimes, when logging on AWS Lambda, some logs don't have time to reach stdout before the lambda shuts down. I haven't dug into this loads but I suspect it's because we're using Pino's async logging. This is a little odd because Pino's docs indicate that logging is set to synchronous in AWS lambda environments.

Node.js version: All
Impacted package(s): @dotcom-reliability-kit/logger

Steps to reproduce

This is quite difficult to reproduce because it relies on loads of executions to turn up, so I haven't bothered. The evidence presented in this FT Slack thread is enough for me.

Expected behaviour

I expect all logs to be sent from Lambdas.

Potential solutions

I don't think options 1 or 3 are viable. I'm happy with either other option but maybe with a slight preference for option 4 to reduce the chance of people opting for sync logs when they don't need to. Thoughts?

1. Try to get async logging working on lambda

The pros of this is that we understand the problem better. The cons are that it'll take a long time to get a fix in and Pino themselves already disable async logging for Lambda. I don't see why we'd be able to resolve this better than they can.

2. Add an explicit option to disable sync logging on Lambda

I'm fine with trying this, but we should also try to work out why Pino's documented behaviour isn't happening. Are we accidentally disabling this behaviour as part of our configuration? A quick glance tells me we're not but it maybe needs more digging into.

If we decide to expose an option then we'd do so by passing a sync: true option into the transport as documented here.

3. Adopt synchronous logging everywhere

I don't want to do this because async logging is more performant (it doesn't block the event loop) in places where it's supportable, i.e. a constantly-running app.

4. Add a flushSync method

A Pino transport has a flushSync method that's explicitly documented as helping with this problem. Maybe we should expose this or switch our own flush method to be use the synchronous one under the hood. We'd then advocate for its use on Lambda via our documentation.

This is what the maintainer of Pino suggests.

If we decide to do this then we could probs just change the logger flush method:

flush() {
-	if (this.transport.flush) {
-		this.transport.flush();
-	}
+	if (this.transport.flushSync) {
+		try {
+			this.transport.flushSync();
+		} catch (error) {
+			// do nothing
+		}
+	}
}