Lambda layer holds MongoDB connections open

[lageorgem]

Hello.

I have had an incident related to the APM Lambda layer on a production environment:

The Elastic instance had failed because of low disk space and was unable to process incoming data. During this incident, it seems that the lambda function had started holding the execution up until the maximum allowed time (32s), which was correlated with a bunch of MongoDB connection issues: Client network socket disconnected before secure TLS connection was established.
After further investigation we have concluded that a possible reason for this was an increase in connections open to the Mongo instance which overloaded it.

As you can see, the issues have started appearing around the same time the instance went down, and was only fixed after redeploying the lambda function without APM enabled.

Is there any way the lambda layer was keeping the execution environment alive while trying to send data to the Elastic instance, given the ELASTIC_APM_DATA_RECEIVER_TIMEOUT_SECONDS variable defaulted to 15s and the Elastic server returned 504?

[AlexanderWert]

Hi @lageorgem ,

thanks for reporting this.

Can you please provide us with the following information, so we can better troubleshoot this issue:

• Which APM agent are you using? (Java, Node.js, Python)
• Which version of the lambda APM extension are you using?
• How did you setup the Agent
• How did you setup the APM lambda extension (e.g. using the public ARN vs. own deployment of the Lambda layer)
• Can you share some Lambda logs (especially the ones emitted by the APM agent and the extension) including the logged errors
• Before the incident with the Elastic instance occurred, have you seen the APM in Kibana and was it complete (including transactions and the MondoDB spans for your Lambda function)?

Thanks!

[lageorgem]

Hello, here is the additional info:

• elastic-apm-node v3.29.0 - NodeJS
• Using APM extension 0.0.3
• The agent is set up using apm.start and apm.lambda as handler
• APM lambda extension is set up using ARN arn:aws:lambda:us-east-1:267093732750:layer:elastic-apm-extension-ver0-0-3-x86_64:3
• The only apparent logs:

2022/02/23 04:59:59 APM server response body: {"ok":false,"message":"Post \"https://172.25.237.116:21555/intake/v2/events\": dial tcp 172.25.237.116:21555: i/o timeout"}

2022/02/23 04:59:59 APM server response status code: 5042022/02/23 04:59:59 APM server response status code: 504

• No known issues before the incident

[trentm]

@lageorgem If you are able to, could you turn on "trace"-logging in the Node.js APM agent (via the ELASTIC_APM_LOG_LEVEL=trace environment variable, or via logLevel: 'trace' in your apm.start({...}) options), reproduce, and share the lambda logs. That might help us isolate the issue.

However, if you aren't able to, we have something to go on from your previous comment to attempt to reproduce.

[lageorgem]

@trentm I am afraid I am not able to do that, as this has happened in a high-volume production environment.

For reference, from what I remember, the Elastic metrics were showing an average throughput of ~5000 tpm, each with its own MongoDB connection established during execution.

In my case, the point of failure was the Mongo instance not being able to keep up with the amount of open connections, however I do believe a good metric for reproduction would be the number of concurrent executions correlated with the lambda reaching the maximum duration even when that duration is sufficiently high.

Please let me know about the status of your investigations at your convenience.

[estolfo]

Hi @lageorgem
Are you able to reproduce this issue or have you only seen it once? If you are able to reproduce it, would you mind turning off the instrumentation for the mongodb driver and letting us know if you still experience the issue?
This is the configuration option you can use to turn off mongodb instrumentation.

[lageorgem]

Hello @estolfo. I have attempted to reproduce, however, I don't seem to be able to simulate a failing Elastic server.
I have tried setting the ELASTIC_APM_LAMBDA_APM_SERVER variable to my own IP, even though I had no server running, hoping to trigger the 504 error.
I have obtained the following error, which is not the same as the one encountered in production:
error forwarding info request (/) to APM Server: Get "https://188.26.232.166/": dial tcp 188.26.232.166:443: i/o timeout.

I did manage to get the maximum duration of the lambdas to the maximum by running a stress test using artillery, but I believe that if I don't get the conditions the same, I won't reproduce the MongoDB issue.

Please advise on how I could simulate a broken Elastic instance, that would allow me to recreate this situation:

2022/02/23 04:59:59 APM server response body: {"ok":false,"message":"Post \"https://172.25.237.116:21555/intake/v2/events\": dial tcp 172.25.237.116:21555: i/o timeout"}

2022/02/23 04:59:59 APM server response status code: 5042022/02/23 04:59:59 APM server response status code: 504