Lambda log entries intermittently taking 1 hour+ to arrive in Cloudwatch

Question

I have a nodejs 14.x lambda function that is called intermittently, sometimes 10 or so calls from 1s to 5 mins apart, and then is left for a couple of days, there is no real pattern - the system is currently coming online, so client use is sporadic.

Sometimes (I counted 5 out of the last 25 invocations, spread across 3 days) the last log entry we make is delayed, from anywhere between 4-5 mins up to 1h50m in one case. Our log entries are timestamped with the logger call time, and the timestamps are in line with the other log calls in the execution. Other calls in the same execution are logged pretty much immediately. The worst example is shown here

![Enter image description here](/media/postImages/original/IMbNCQQG0RRwC7TdqHDca8Ow)

The function is using middy to log the returned data in an after handler, and is the same for all invocations (i.e. we are not doing a different log call etc in some cases). The function has provisioned concurrency enabled to reduce the cold startup times.

Can anyone explain why this should be? This is running in us-east-2, and attached to our own VPC.

Accepted Answer

When your function returns to the caller, the Lambda service freezes the execution environment and nothing happens there until there is another invocation, or until the execution environment is shutdown.

If you look at your trace you see that the last log message is printed after the END message. My assumption is that because you are using Node.js, the event loop is not empty when you return. This external [blog](https://medium.com/radient-tech-blog/aws-lambda-and-the-node-js-event-loop-864e48fba49) explains it very well. The following [documentation](https://docs.aws.amazon.com/lambda/latest/dg/nodejs-handler.html) explains how to use `callbackWaitsForEmptyEventLoop` to resolve this.

Lambda log entries intermittently taking 1 hour+ to arrive in Cloudwatch

Contenus pertinents