Serverless-offline: v3.20.3 on Node 8.10 causes Warning: context.done called twice within handler

[anishkny]

Issue can be seen in this repo:

• Reproduced in v3.20.3
• Does not reproduce when pinned to v3.20.2

[willfarrell]

Switching from callback to using async oddly solved it for me.

[necevil]

@willfarrell could you elaborate on your switch to async? Thinking about doing something similar but not sure where to start.

[willfarrell]

@necevil Sure, here is a simple sample:

const handler = async (event, context) => {
  const { id } = event.pathParameters

  await Promise.resolve()

  return {
    statusCode: 200,
    body: JSON.stringify({ id })
  }
}
module.exports = { handler }

[DJviolin]

I had similar error within the Serverless Stack example:

import * as dynamoDbLib from '../libs/dynamodb-lib';
import { success, failure } from '../libs/response-lib';

export async function main(event, context, callback) {
  const params = {
    TableName: 'notes',
    KeyConditionExpression: 'userId = :userId',
    ExpressionAttributeValues: {
      ':userId': event.requestContext.identity.cognitoIdentityId,
    },
  };

  try {
    const result = await dynamoDbLib.call('query', params);
    callback(null, success(result.Items));
  } catch (e) {
    callback(null, failure({ status: false }));
  }
}

I solved by simply following the official implementation example in the blog:

let AWS = require('aws-sdk');
let lambda = new AWS.Lambda();
let data;

exports.handler = async (event) => {
    try {
        data = await lambda.getAccountSettings().promise();
    }
    catch (err) {
        console.log(err);
        return err;
    }
    return data;
};

So the upper example looks like this:

import * as dynamoDbLib from '../libs/dynamodb-lib';
import { success, failure } from '../libs/response-lib';

let data;

export const main = async (event) => {
  const params = {
    TableName: 'notes',
    KeyConditionExpression: 'userId = :userId',
    ExpressionAttributeValues: {
      ':userId': event.requestContext.identity.cognitoIdentityId,
    },
  };

  try {
    data = await dynamoDbLib.call('query', params);
  } catch (err) {
    console.log(err);
    return failure({ status: false });
  }

  return success(data.Items);
};

[anonmos]

This bit me today with one of my handlers, which stopped resolving all together without a response. The bug seems to have existed for about 2 years now, but reared its ugly head when this commit forced nodejs8.10 to use Promise support.

When I downloaded serverless-offline and linked it locally, then sifted through where responses are returned, it looks like this line immediately evaluates lambdaContext.succeed, rather than defining an anonymous function for evaluation when it's called later:

if (x && typeof x.then === 'function' && typeof x.catch === 'function') x.then(lambdaContext.succeed).catch(lambdaContext.fail);

When I instead replaced that line with this, the error went away and it started resolving correctly:

if (x && typeof x.then === 'function' && typeof x.catch === 'function') {
  x.then(() => lambdaContext.succeed)
   .catch(() => lambdaContext.fail);
} 

I'll see if I can't get a PR put together to fix it. But in case I don't get to it, ☝️ seems to be the solution.

[juanjoDiaz]

@anonmos Your solution is not calling succeed or fail at all.

.then(lambdaContext.succeed) is the same as .then(() => lambdaContext.succeed()) but you are missing the calling parenthesis.

The problem is that succeed or fail are called regardless of whether the user already called the callback or not. Not sure if there is a property in the context that could be checked to see if the user has already called the callback.

[anonmos]

@juanjoDiaz Good point, my mistake. That'll teach me to debug tired 🙃

What my previous comment did, though, was remove the call of lambdaContext.succeed, and allowed my async handler function to execute properly, call the provided callback function (lambdaContext.done, in my case), and for my client to receive a response as expected. Taking a step back, this begs the question of _why_ we need to "Add async handler support" in the form of attempting to call lambdaContext.succeed() (which isn't even listed as a method in the docs any longer) for node8.10 at all?

When I revert the commit, everything runs as expected. ~@domaslasauskas can you shed some light on the use case for your commit?~ Nevermind, I see the use case, per here.

To summarize, I see two issues:

• lambdaContext.succeed is _always_ evaluated immediately
• Backwards compatibility with the callback pattern isn't currently supported for the use case of upgrading from node6.10->node8.10

My proposed solution:

• Separate cross-cutting versions of node (use lambdaContext.succeed() for 0.10)
• Differentiate between a returned Promise and a lambdaContext.done call properly to maintain backwards compatibility for >=node4.3.2

Thoughts?

[dherault]

Hi, I would like to work on this issue. Can someone give me a failing example where the issue shows up ? Thanks.

[anishkny]

I am able to repro with this minimal setup:

## serverless.yml
service:
  name: myService
provider:
  name: aws
  runtime: nodejs8.10
plugins:
  - serverless-offline
functions:
  hello:
    handler: index.hello
    events:
      - http: GET /

// index.js
module.exports.hello = async function(event, context, callback) {
  await new Promise(resolve => setTimeout(resolve, 1000));
  callback(null, {
    statusCode: 200,
    body: JSON.stringify({ "message": "Hello World!" }),
  });
}

{
  "dependencies": {
    "serverless": "^1.27.3",
    "serverless-offline": "^3.24.4"
  }
}

Output:

% npx sls offline &
[1] 75725
% Serverless: Starting Offline: dev/us-east-1.

Serverless: Routes for hello:
Serverless: GET /

Serverless: Offline listening on http://localhost:3000

% curl http://localhost:3000

Serverless: GET / (λ: hello)
Serverless: The first request might take a few extra seconds
Serverless: [200] {"statusCode":200,"body":"{\"message\":\"Hello World!\"}"}

Serverless: Warning: context.done called twice within handler 'hello'!
{"message":"Hello World!"}

[robertleeplummerjr]

You guys rock.

[brorio]

Strange I get this warning with Serverless-offline 3.30.0 and Node 8.12:

Serverless: GET /api/test (λ: test)
Serverless: The first request might take a few extra seconds
Serverless: [200] {"statusCode":200,"headers":{"Access-Control-Allow-Origin":"*","Access-Control-Allow-Credentials":true},"body":"{\"message\":\"Hi ⊂◉‿◉つ from Private API. Only logged in users can see this\"}"}
Serverless: Warning: callback called twice within Auth function 'auth'!

Juat testing with this Custom Authorizer: https://github.com/serverless/examples/tree/master/aws-node-auth0-custom-authorizers-api

{
  "name": "aws-auth0-api-gateway",
  "version": "1.0.0",
  "description": "Demonstration of protecting API gateway endpoints with auth0",
  "license": "MIT",
  "dependencies": {
    "jsonwebtoken": "^8.3.0"
  },
  "devDependencies": {
    "serverless-offline": "^3.30.0"
  }
}

[dherault]

@brorio Can you give us your auth function handler please ?

[juanjoDiaz]

I assume, that the auth function comes from the repo he posted: https://github.com/serverless/examples/blob/master/aws-node-auth0-custom-authorizers-api/handler.js#L26

I took a look but couldn't see any reason why the callback is being called twice.

[dherault]

Same here... mmm weird. I cannot explain it... Its possible jwt.verify both throws and calls its callback, thus resulting in callback called twice...

[juanjoDiaz]

Thanks @dherault you just gave me the hint I needed.

The code is just wrong:

  try {
    jwt.verify(tokenValue, AUTH0_CLIENT_PUBLIC_KEY, options, (verifyError, decoded) => {
      if (verifyError) {
        console.log('verifyError', verifyError);
        // 401 Unauthorized
        console.log(`Token invalid. ${verifyError}`);
        return callback('Unauthorized');
      }
      // is custom authorizer function
      console.log('valid from customAuthorizer', decoded);
      return callback(null, generatePolicy(decoded.sub, 'Allow', event.methodArn));
    });
  } catch (err) {
    console.log('catch error. Invalid token', err);
    return callback('Unauthorized');
  }

  // if for any reason you get here...
  // THIS IS THE PROBLEM: of course you get here. `jwt.verify` is async,
  // so you always hit this first and the `jwt.verify`'s callback is executed later. 
  // So you always call `callback` twice.
  // Remove this line and everything will work as you expect.
  return callback('Unauthorized');

[dherault]

Aaaaaw I thought I had it. Nice.

[anishkny]

Social coding ftw!

[nenti]

I still have this issue with newest version of serverless offline. Handler works on lambda because async doesn't only mean I don't want to use a callback but also is just a regular nodejs pattern to handle async functions. For serverless-offline this is not possible to use async together with callback.

[kjellski]

I still have the same issue as well. Any idea of what the culprit could be?

@nenti - did you solve this for yourself?

[dnalborczyk]

@kjellski which serverless-offline version are you using? could you create a small repro repository to have a look?

[kjellski]

@dnalborczy I've used latest for it and all packages. Will do a reproduction repo when I'm back at work :+1: