Aws-xray-sdk-node: AWS Lambda Node 8.10 Runtime Support

[ianwremmel]

It looks like the xray sdk instruments the handler with the assumption that the handler will follow the callback pattern required in node 4 and 6. With node 8, async functions are available (and encouraged in the node 8 on lambda blog post), but including the sdk without wrapping the async handler fails.

Working:

exports.handler = async() => ({statusCode: 200});

HTTP/1.1 200 OK

Broken:

require('aws-xray-sdk');

exports.handler = async() => ({statusCode: 200});

HTTP/1.1 502 Bad Gateway

{
    "message": "Internal server error"
}

Workaround:

require('aws-xray-sdk');

exports.handler = (event, context, callback) => {
  run()
    .then((res) => callback(null, res))
    .catch((err) => callback(err));
};

async function run() {
  return {statusCode: 200};
}

HTTP/1.1 200 OK

[haotianw465]

You can find more details in this thread: https://github.com/aws/aws-xray-sdk-node/issues/12 around async support. Please let me know if you have additional questions.

Could you provide the server side stack trace on the 5xx?

[ianwremmel]

There's actually no server-side stack trace. The lambda code executes correctly, but passes a promise instead of a response object back to API Gateway which doesn't know how to handle it. The API Gateway logs (once you figure out how to enable them) says:

Execution failed due to configuration error: Malformed Lambda proxy response

[haotianw465]

We will do some testing around the new Lambda node runtime and update the thread soon. One thing to confirm is that for the 502 you simply did require('aws-xray-sdk'); with no other code that could be traced correct?

[ianwremmel]

The three examples I posted are the only code I wrote. I'm using serverless and serverless-webpack to build and deploy, so there is some transformation that happens. It does occure to me that the serverless sentry plugin was also involved which might wrap it. Under those conditions, require('aws-xray-sdk') does appear to be the only variable across tests. That said, I'll try to test it tonight with the sentry plugin and webpack disabled.

[haotianw465]

Thank you for the information. We will also do some testing around raw Lambda function to start with.

[mooyoul]

If you guys need simple reproducible steps, please refer #29.

[haotianw465]

Another report https://github.com/aws/aws-xray-sdk-node/issues/29 for the same issue. I successfully reproduced the issue using the hello world example Lambda provides.

[haotianw465]

It looks like the problem happens on CLS which the SDK has direct dependency on.

Here is a repro:
Repro index.js

require('continuation-local-storage');

exports.handler = async (event) => {
    return 'Hello from Lambda!';
};

Test event result:

Response:
null

The working index.js

//require('continuation-local-storage');

exports.handler = async (event) => {
    return 'Hello from Lambda!';
};

Test event result:

Response:
"Hello from Lambda!"

So it looks like the new async handler provided by Lambda node 8.10 runtime will have issues if your application code has indirect dependency on CLS.

We will contact Lambda team for more insights. Ideally simply importing CLS should not affect what the async handler returns.

[mooyoul]

after more investigation, it seems depending package async-listener in CLS makes this behavior.

more specific re-pro code:

module.exports.foo = async (event) => 
  require('async-listener');
  return 3;
}

The async-listener patches core modules of Node.js, somehow it breaks lambda node.js 8.10 runtime.

[mooyoul]

Okay. here some code goes:
async-listener do monkey-patch to native Promise, and change global.Promise to wrapped version of promise they have.

so it causes the issue. interesting thing is:

'use strict';

// below function results `null` anyway
module.exports.hello = async (event) => {
  const p = new Promise((resolve) => setTimeout(resolve, 1000 * 10));

  // Backup original promise
  const originalPromise = global.Promise;

  require('async-listener');
  // Now promise is patched by async-listener

  console.log('Promise is same before?', global.Promise === originalPromise); // prints false, funny!

  // Promise detection is broken also:
  const isPromise = Promise.resolve(p) === p; // surprise!
  console.log('isPromise?', isPromise); // false. wait, what????? we expected true!

  return 3;
};

'use strict';

// surprise! we can get 3!
module.exports.hello = async (event) => {
  // Backup original promise
  const originalPromise = global.Promise;

  require('async-listener');
  // Now promise is patched by async-listener

  // Simply restore original Promise
  global.Promise = originalPromise;

  return 3;
};

[mooyoul]

Okay. Finally i found the reason why lambda returns null.

Here goes:

1. when requires aws-xray-sdk-core package from user land, it requires continuation-local-storage package internally
2. continuation-local-storage package requires async-listener package internally
3. async-listener patches global.Promise object
4. Lambda runtime fails Promise checking (see below screenshot)

According to Line 287~290 (end of invoke function) on/var/runtime/node_modules/awslambda/index.js
it uses response instanceof Promise to check given object is instance of Promise object.
but on step (3), global.Promise was mutated by async-listener. so it results false and lambda runtime treats this response as non-promise object.

so for now below two code will have same effect:

'use strict';

module.exports.hello = async (event) => {
  require('async-listener'); // patches global.Promise object
  return 3;
};

'use strict';

const BbPromise = require('bluebird');

module.exports.hello = (event) => BbPromise.resolve(3); // returns instance of bluebird promise

[mooyoul]

so to Lambda team:

Please use thenable object check instead of using instanceof Promise like below:

if (response && typeof response.then === 'function') { // given response is promise-like object
  response.then(context.succeed);
  response.catch(context.fail);
}

Please note Node.js project has thenable test suite, so if you need some tests please refer here:
https://github.com/nodejs/node/tree/db1087c9757c31a82c50a1eba368d8cba95b57d0/deps/v8/test/webkit/fast/js

[awssandra]

Hi Mooyoul,

Thank you for the detailed deep dive. We have reached out to the Lambda team and will be following up on this ASAP.

Sorry for the trouble,
Sandra

[murilodag]

Hello @awssandra , do you have a timeline for those changes?

[awssandra]

@murilodag

We are continuing to prioritize this fix with the Lambda team. Please stay tuned for updates, we'll update this thread accordingly when we have more news.

Sorry for the trouble,
Sandra

[pedrocarrico]

I've also experienced this issue when returning a Bluebird promise in AWS lambda using the node 8.10 runtime, thanks for the explanation @mooyoul 👍

[muriloamendola]

We are facing this problem too!

[breath103]

This can be fixed from xray sdk also if you just find an alternative for CLS. i mean whole problem is that CLS override global Promise with bluebird
@awssandra How about just finding an alternative of CLS and publish new version of aws-xray-sdk? this seems getting dragged

[awssandra]

@breath103

We have a path to resolution with Lambda and are hoping for fixed to be release soon. We are aware of the unfortunately long time this has taken, and appreciate your continued patience as we work with Lambda to fix this correctly. We plan to work more closely with Lambda in future releases so that we can identify and fix incompatibilities/issues early.

Sorry for the trouble,
Sandra

[davidkelley]

Any update on this issue?

[johnforte]

@awssandra can we get an ETA on this, as this is a critical bug I feel like and prevents people from fully using xray.

[mooyoul]

so for now, there's only one option that we can do:
Use callback. yeah, maybe it sounds ugly. but will work without having any issues.

For example:

const BbPromise = require('bluebird');

module.exports.foo = wrap(async (event) => {
  return 3;
});

function wrap(handler) {
  return (event, context, callback) => {
    BbPromise.resolve(handler(event, context)).asCallback(callback);
  };
}

[LuukMoret]

Will this ever get fixed? A lot of people are using node 8 runtime and don't want to use callbacks.

[dimkir]

I was hit by simply returning bluebird promise and receiving mysterious null value, along with API Gateway generic Internal Server Error.

Looks exactly like what @mooyoul has described in detail.

Is there a ticket or smth. on this issue on some public Lambda team tracker?

[awssandra]

Hi everyone,

We're moving on this with the Lambda team as we speak, thank you for all of your patience. We'll update as soon as we can.

[kevinrambaud]

Hi, any update?

Edit:

nvm, in the meantime I'll just use @mooyoul callbackify trick with native Promises

const util = require('util');

async function hello(event, context) {
  return { event, context, message: 'Hello world!' };
}

exports.handler = util.callbackify(hello);

[awssandra]

Hi everyone,

Lambda has finished rolling out the fix. Please let us know of any further issues. Thank you again for all your patience.

[dimkir]

Just tested this in eu-west-1 works like a charm! Now I can return bluebird promises!

Here's snippet I used to test

'use strict';

const bbPromise = global.Promise = require('bluebird');

module.exports.handler = async (event, context) => {

  return new bbPromise((resolve, reject)=>{


    let response =  {
      statusCode: 200,
      body: JSON.stringify({
        message: 'If you see this, you returned bluebird promise from async function upstream to Lambda 8.10 Runtime!',
      }),
    };

    setTimeout(()=>{
      resolve(response);
    }, 3000);

  });

};

[Enase]

How to test? I don't see any new version..

[awssandra]

@Enase

The Lambda 8.10 runtime was updated from Lambda's end. All existing Lambda 8.10 functions have been updated behind the scenes, and should no longer break with the existing X-Ray SDK.

[mooyoul]

Confirmed Thenable check:

Now we can use any Promise implementations as return value. Yay!