ARM64 Lambda failing with Maximum call stack size exceeded when tracing enabled

ahernandez2-rbi commented 2 years ago

Expected behaviour Lambda to work properly after changing the architecture from x86 to arm64

Actual behaviour Lambda fails to execute with "Maximum call stack size exceeded" error.

Environment

Operation system: AWS Lambda environment
Node.js version: Node.js 14.x

I'm trying to migrate an AWS Lambda from x86 to arm64 and when the lambda is executed it fails with the following error:

{
    "errorType": "RangeError",
    "errorMessage": "Maximum call stack size exceeded",
    "stack": [
        "RangeError: Maximum call stack size exceeded",
        "    at get (internal/bootstrap/pre_execution.js:309:7)",
        "    at addData (/var/task/node_modules/serverless-http/lib/response.js:21:3)",
        "    at Object.write (/var/task/node_modules/serverless-http/lib/response.js:108:11)",
        "    at ServerResponse._writeRaw (_http_outgoing.js:351:17)",
        "    at ServerResponse._send (_http_outgoing.js:327:15)",
        "    at ServerResponse.end (_http_outgoing.js:849:10)",
        "    at ServerResponse.<anonymous> (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31)",
        "    at /opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31",
        "    at /opt/nodejs/node_modules/dd-trace/packages/datadog-plugin-http/src/server.js:60:70",
        "    at Subscription._handler (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/plugin.js:12:9)",
        "    at Channel.publish (diagnostics_channel.js:56:9)",
        "    at ServerResponse.emit (/opt/nodejs/node_modules/dd-trace/packages/datadog-instrumentations/src/http/server.js:33:24)",
        "    at ServerResponse.emitted (/var/task/node_modules/emitter-listener/listener.js:134:21)",
        "    at onFinish (_http_outgoing.js:792:10)",
        "    at Object.write (/var/task/node_modules/serverless-http/lib/response.js:125:11)",
        "    at ServerResponse._writeRaw (_http_outgoing.js:351:17)",
        "    at ServerResponse._send (_http_outgoing.js:327:15)",
        "    at ServerResponse.end (_http_outgoing.js:849:10)",
        "    at ServerResponse.<anonymous> (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31)",
        "    at /opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31",
        "    at /opt/nodejs/node_modules/dd-trace/packages/datadog-plugin-http/src/server.js:60:70",
        "    at Subscription._handler (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/plugin.js:12:9)"
    ]
}

If I change the env var DD_TRACE_ENABLED=true to DD_TRACE_ENABLED=false it starts working fine.

The lambda is integrated with DD using the serverless-datadog-plugin@5.0.0 which is adding the following layers:

arn:aws:lambda:us-east-1:464622532012:layer:Datadog-Node14-x:77 arn:aws:lambda:us-east-1:464622532012:layer:Datadog-Extension-ARM:21

The first DD layer is bringing version 2.5.0 of dd-trace

bengl commented 2 years ago

This seems to be the same issue as https://github.com/DataDog/dd-trace-js/issues/2045

ahernandez2-rbi commented 2 years ago

@bengl yes! Same issue. A few notes though:

The issue you pointed me to uses the package @vendia/serverless-express, while we use the serverless-http. They both serve the same purpose: take the lambda event payload and transform it to make it look like an nodejs Request object and the same on the way out with the Response. As part of the troubleshooting I switched to @vendia/serverless-express, but also ran into the same issue.
Without doing the Error.stackTraceLimit = 100 trick, we can already see from the stacktrace in this issue we are getting into some kind of infinite recursion.
Weirdly enough, this doesn't happen when the lambda runs on x86. Could it be that the thread stack size is bigger in x86 and it eventually ends?

Have you determine the root cause? If not, let me know if there is anything you would want me to try to help.

astuyve commented 2 years ago

Hi @ahernandez2-rbi - serverless-express and serverless-http share a lot of the same code, including where this trace runs (https://github.com/dougmoscrop/serverless-http/blob/master/lib/response.js and https://github.com/vendia/serverless-express/blob/mainline/src/response.js).

I haven't been able to reproduce this successfully with a minimal project, using either koa or express. Can you share any relevant handler code and app setup code?

Mine looks like this: app.js

const { getCurrentInvoke } = require('@vendia/serverless-express')
const express = require('express')
const bodyParser = require('body-parser')
const app = express()
const router = express.Router()

router.use(bodyParser.json())
router.use(bodyParser.urlencoded({ extended: true }))

router.get('/users/', (req, res) => {
  res.json({success: true})
})

app.use('/', router)

module.exports = app

lambda.js

const serverlessExpress = require('@vendia/serverless-express')
const app = require('./app')
exports.handler = serverlessExpress({ app })

ahernandez2-rbi commented 2 years ago

@astuyve I'll see if I can repro in a simple lambda and share. Here are a few things you can try on your lambda:

Use larger response payloads. That will probably cause multiple ServerResponse._writeRaw calls.
Issue #2045 uses Apollo GraphQL, our lambda also uses it. Might be worth giving that a try.

astuyve commented 2 years ago

Okay thanks @ahernandez2-rbi. I've followed the lambda setup for serverless as per the apollo docs, but it's running normally and returning 200ok, and traces are showing up in Datadog:

I'll try increasing the payload size

ahernandez2-rbi commented 2 years ago

@astuyve I see the lambda architecture is x86, can you change it to arm64?

ahernandez2-rbi commented 2 years ago

@astuyve I was able to create a simple repro. No GraphQL required, simple express app.

package.json:

{
  "name": "dd-stack-limit-repro",
  "version": "1.0.0",
  "description": "",
  "main": "index.js",
  "scripts": {
    "test": "echo \"Error: no test specified\" && exit 1"
  },
  "author": "",
  "license": "ISC",
  "dependencies": {
    "express": "4.18.1",
    "serverless-http": "3.0.1"
  }
}

index.js

const serverless = require('serverless-http');
const express = require('express');

Error.stackTraceLimit = 100;
const app = express();
app.get('/', async (req, res) => {
  res.json({
    query: req.query,
    headers: req.headers,
  });
});

exports.handler = serverless(app);

AWS Lambda SAM file:

AWSTemplateFormatVersion: '2010-09-09'
Transform: 'AWS::Serverless-2016-10-31'
Description: An AWS Serverless Specification template describing your function.
Resources:
  ddstacklimitrepro:
    Type: 'AWS::Serverless::Function'
    Properties:
      Architectures:
        - arm64
      Handler: '/opt/nodejs/node_modules/datadog-lambda-js/handler.handler'
      Runtime: nodejs14.x
      CodeUri: .
      Description: ''
      MemorySize: 128
      Timeout: 3
      Role: >-
        arn:aws:iam::some-account:role/service-role/dd-stack-limit-repro-role-nz6gd2r4
      Environment:
        Variables:
          DD_SITE: datadoghq.com
          DD_LOGS_INJECTION: 'false'
          AWS_NODEJS_CONNECTION_REUSE_ENABLED: '1'
          DD_TRACE_ENABLED: 'true'
          DD_ENV: dev
          DD_LAMBDA_HANDLER: index.handler
          DD_SERVICE: dd-stack-limit-repro
          DD_ENHANCED_METRICS: 'true'
          DD_VERSION: '1'
          DD_TRACE_DEBUG: 'true'
          DD_API_KEY: some-api-key
      Tags:
        app: dd-stack-limit-repro
        stage: dev
        service: dd-stack-limit-repro
        env: dev
        version: '1'
      Layers:
        - 'arn:aws:lambda:us-east-1:464622532012:layer:Datadog-Node14-x:77'
        - 'arn:aws:lambda:us-east-1:464622532012:layer:Datadog-Extension-ARM:21'

Cloudwatch error:

{
    "errorType": "RangeError",
    "errorMessage": "Maximum call stack size exceeded",
    "stack": [
        "RangeError: Maximum call stack size exceeded",
        "    at Array.values (<anonymous>)",
        "    at ServerResponse.<anonymous> (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:292:39)",
        "    at /opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31",
        "    at /opt/nodejs/node_modules/dd-trace/packages/datadog-plugin-http/src/server.js:60:70",
        "    at Subscription._handler (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/plugin.js:12:9)",
        "    at Channel.publish (diagnostics_channel.js:56:9)",
        "    at ServerResponse.emit (/opt/nodejs/node_modules/dd-trace/packages/datadog-instrumentations/src/http/server.js:33:24)",
        "    at onFinish (_http_outgoing.js:792:10)",
        "    at Object.write (/var/task/node_modules/serverless-http/lib/response.js:125:11)",
        "    at ServerResponse._writeRaw (_http_outgoing.js:351:17)",
        "    at ServerResponse._send (_http_outgoing.js:327:15)",
        "    at ServerResponse.end (_http_outgoing.js:849:10)",
        "    at ServerResponse.<anonymous> (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31)",
        "    at /opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31",
        "    at /opt/nodejs/node_modules/dd-trace/packages/datadog-plugin-http/src/server.js:60:70",
        "    at Subscription._handler (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/plugin.js:12:9)",
        "    at Channel.publish (diagnostics_channel.js:56:9)",
        "    at ServerResponse.emit (/opt/nodejs/node_modules/dd-trace/packages/datadog-instrumentations/src/http/server.js:33:24)",
        "    at onFinish (_http_outgoing.js:792:10)",
        "    at Object.write (/var/task/node_modules/serverless-http/lib/response.js:125:11)",
        "    at ServerResponse._writeRaw (_http_outgoing.js:351:17)",
        "    at ServerResponse._send (_http_outgoing.js:327:15)",
        "    at ServerResponse.end (_http_outgoing.js:849:10)",
        "    at ServerResponse.<anonymous> (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31)",
        "    at /opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31",
        "    at /opt/nodejs/node_modules/dd-trace/packages/datadog-plugin-http/src/server.js:60:70",
        "    at Subscription._handler (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/plugin.js:12:9)",
        "    at Channel.publish (diagnostics_channel.js:56:9)",
        "    at ServerResponse.emit (/opt/nodejs/node_modules/dd-trace/packages/datadog-instrumentations/src/http/server.js:33:24)",
        "    at onFinish (_http_outgoing.js:792:10)",
        "    at Object.write (/var/task/node_modules/serverless-http/lib/response.js:125:11)",
        "    at ServerResponse._writeRaw (_http_outgoing.js:351:17)",
        "    at ServerResponse._send (_http_outgoing.js:327:15)",
        "    at ServerResponse.end (_http_outgoing.js:849:10)",
        "    at ServerResponse.<anonymous> (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31)",
        "    at /opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31",
        "    at /opt/nodejs/node_modules/dd-trace/packages/datadog-plugin-http/src/server.js:60:70",
        "    at Subscription._handler (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/plugin.js:12:9)",
        "    at Channel.publish (diagnostics_channel.js:56:9)",
        "    at ServerResponse.emit (/opt/nodejs/node_modules/dd-trace/packages/datadog-instrumentations/src/http/server.js:33:24)",
        "    at onFinish (_http_outgoing.js:792:10)",
        "    at Object.write (/var/task/node_modules/serverless-http/lib/response.js:125:11)",
        "    at ServerResponse._writeRaw (_http_outgoing.js:351:17)",
        "    at ServerResponse._send (_http_outgoing.js:327:15)",
        "    at ServerResponse.end (_http_outgoing.js:849:10)",
        "    at ServerResponse.<anonymous> (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31)",
        "    at /opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31",
        "    at /opt/nodejs/node_modules/dd-trace/packages/datadog-plugin-http/src/server.js:60:70",
        "    at Subscription._handler (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/plugin.js:12:9)",
        "    at Channel.publish (diagnostics_channel.js:56:9)",
        "    at ServerResponse.emit (/opt/nodejs/node_modules/dd-trace/packages/datadog-instrumentations/src/http/server.js:33:24)",
        "    at onFinish (_http_outgoing.js:792:10)",
        "    at Object.write (/var/task/node_modules/serverless-http/lib/response.js:125:11)",
        "    at ServerResponse._writeRaw (_http_outgoing.js:351:17)",
        "    at ServerResponse._send (_http_outgoing.js:327:15)",
        "    at ServerResponse.end (_http_outgoing.js:849:10)",
        "    at ServerResponse.<anonymous> (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31)",
        "    at /opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31",
        "    at /opt/nodejs/node_modules/dd-trace/packages/datadog-plugin-http/src/server.js:60:70",
        "    at Subscription._handler (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/plugin.js:12:9)",
        "    at Channel.publish (diagnostics_channel.js:56:9)",
        "    at ServerResponse.emit (/opt/nodejs/node_modules/dd-trace/packages/datadog-instrumentations/src/http/server.js:33:24)",
        "    at onFinish (_http_outgoing.js:792:10)",
        "    at Object.write (/var/task/node_modules/serverless-http/lib/response.js:125:11)",
        "    at ServerResponse._writeRaw (_http_outgoing.js:351:17)",
        "    at ServerResponse._send (_http_outgoing.js:327:15)",
        "    at ServerResponse.end (_http_outgoing.js:849:10)",
        "    at ServerResponse.<anonymous> (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31)",
        "    at /opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31",
        "    at /opt/nodejs/node_modules/dd-trace/packages/datadog-plugin-http/src/server.js:60:70",
        "    at Subscription._handler (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/plugin.js:12:9)",
        "    at Channel.publish (diagnostics_channel.js:56:9)",
        "    at ServerResponse.emit (/opt/nodejs/node_modules/dd-trace/packages/datadog-instrumentations/src/http/server.js:33:24)",
        "    at onFinish (_http_outgoing.js:792:10)",
        "    at Object.write (/var/task/node_modules/serverless-http/lib/response.js:125:11)",
        "    at ServerResponse._writeRaw (_http_outgoing.js:351:17)",
        "    at ServerResponse._send (_http_outgoing.js:327:15)",
        "    at ServerResponse.end (_http_outgoing.js:849:10)",
        "    at ServerResponse.<anonymous> (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31)",
        "    at /opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31",
        "    at /opt/nodejs/node_modules/dd-trace/packages/datadog-plugin-http/src/server.js:60:70",
        "    at Subscription._handler (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/plugin.js:12:9)",
        "    at Channel.publish (diagnostics_channel.js:56:9)",
        "    at ServerResponse.emit (/opt/nodejs/node_modules/dd-trace/packages/datadog-instrumentations/src/http/server.js:33:24)",
        "    at onFinish (_http_outgoing.js:792:10)",
        "    at Object.write (/var/task/node_modules/serverless-http/lib/response.js:125:11)",
        "    at ServerResponse._writeRaw (_http_outgoing.js:351:17)",
        "    at ServerResponse._send (_http_outgoing.js:327:15)",
        "    at ServerResponse.end (_http_outgoing.js:849:10)",
        "    at ServerResponse.<anonymous> (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31)",
        "    at /opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/util/web.js:302:31",
        "    at /opt/nodejs/node_modules/dd-trace/packages/datadog-plugin-http/src/server.js:60:70",
        "    at Subscription._handler (/opt/nodejs/node_modules/dd-trace/packages/dd-trace/src/plugins/plugin.js:12:9)",
        "    at Channel.publish (diagnostics_channel.js:56:9)",
        "    at ServerResponse.emit (/opt/nodejs/node_modules/dd-trace/packages/datadog-instrumentations/src/http/server.js:33:24)",
        "    at onFinish (_http_outgoing.js:792:10)",
        "    at Object.write (/var/task/node_modules/serverless-http/lib/response.js:125:11)",
        "    at ServerResponse._writeRaw (_http_outgoing.js:351:17)",
        "    at ServerResponse._send (_http_outgoing.js:327:15)",
        "    at ServerResponse.end (_http_outgoing.js:849:10)"
    ]
}

astuyve commented 2 years ago

This is great, thank you! I tried switching my example to ARM and saw no change. Reproducing with your example now, will update as soon as I can.

astuyve commented 2 years ago

Thanks again for this reproduction case. I was able to replicate this issue specifically using SAM and version 77 of the Lambda Layer, but when I manually installed the layer code and this tracer, I wasn't able to trigger this looping behavior.

That makes this a bit more complex to debug :) I will provide more updates when I'm able to reproduce with a local build of the layer/tracer.

Thanks again!

astuyve commented 2 years ago

Hi @ahernandez2-rbi - could you try this again with version 78? arn:aws:lambda:us-east-1:464622532012:layer:Datadog-Node14-x:78.

Thanks!

ahernandez2-rbi commented 2 years ago

@astuyve it worked!!! I noticed that the serverless-datadog-plugin@5.1.0 was released and it includes this new layer version. I think I should be good to go. Is there anything else I should do?

astuyve commented 2 years ago

Great, thanks! We in datadog-lambda-js and serverless-plugin-datadog were a bit behind this library (dd-trace-js). Upgrading to the latest (2.7.1) fixes this issue.

There shouldn't be anything else on your end, thanks again!

cayter commented 2 years ago

This is still happening for NodeJS 16.x with v2.7.1.

astuyve commented 2 years ago

Hi @cayter - thanks for reaching out. I tried this same stack shared here, using node 16 and layer version 78 (which uses v2.7.1 of dd-trace), and the function successfully ran:

Is there a minimally-reproducible case you can share here that would help me reproduce this?

cayter commented 2 years ago

@astuyve Sorry for the wrong info, I just tested again and realised I had a misconfiguration, it seems working now. Thanks.

DataDog / dd-trace-js

ARM64 Lambda failing with Maximum call stack size exceeded when tracing enabled #2046