Async function is exited prematurely

[tommedema]

This is a bug report

Description

For bug reports:

• What went wrong?

My handler function is defined as follows:

export const onBucketUpload = async (
  event: S3Event,
  context: APIGatewayEventRequestContext
): Promise<void> => {
  // tslint:disable-next-line: no-console
  console.info(`
    onBucketUpload fired with:
    
    event: ${JSON.stringify(event)}
    context: ${JSON.stringify(context)}
  `)

  const objectInfo = getObjectInfoFromS3Event(event)
  const sketchFile = await fetchObjectFromS3(objectInfo)
  const projectFiles = await getProjectFiles(sketchFile)

  console.info(`
    generated project files:

    ${projectFiles.map(f => `${f.path} (${f.data.length} bytes)`).join('\n')}
  `)
}

Together with the Typescript resolver, this compiles to:

exports.onBucketUpload = (event, context) => __awaiter(this, void 0, void 0, function* () {
    // tslint:disable-next-line: no-console
    console.info(`
    onBucketUpload fired with:
    
    event: ${JSON.stringify(event)}
    context: ${JSON.stringify(context)}
  `);
    const objectInfo = exports.getObjectInfoFromS3Event(event);
    const sketchFile = yield exports.fetchObjectFromS3(objectInfo);
    const projectFiles = yield exports.getProjectFiles(sketchFile);
    console.info(`
    generated project files:

    ${projectFiles.map(f => `${f.path} (${f.data.length} bytes)`).join('\n')}
  `);
});

Seems OK. But when running this on AWS lambda, the logs give:

START RequestId: e74e2acf-a487-11e8-a4bc-75bebe154b8e Version: $LATEST
2018-08-20T14:47:05.980Z	e74e2acf-a487-11e8-a4bc-75bebe154b8e	
onBucketUpload fired with:

event:
{
    "Records": [
        {
            "eventVersion": "2.0",
            "eventSource": "aws:s3",
            "awsRegion": "us-east-1",
            "eventTime": "2018-08-20T14:47:04.233Z",
            "eventName": "ObjectCreated:Put",
            "userIdentity": {
                "principalId": "A3GISO2WDBCEWM"
            },
            "requestParameters": {
                "sourceIPAddress": "179.111.111.220"
            },
            "responseElements": {
                "x-amz-request-id": "073289BE50F8417B",
                "x-amz-id-2": "vUlVPvk2jGHWU41G6lzMyYNW1hFlOioWftWnqwntrFtTEw87rRwW6Qnf7/PPkQlcrjywwMjZ0aY="
            },
            "s3": {
                "s3SchemaVersion": "1.0",
                "configurationId": "ec6e73bf-3734-4c60-819a-917e562e5f54",
                "bucket": {
                    "name": "vg-diy-bucket-dev-diybucket-1qxql8dgn091j",
                    "ownerIdentity": {
                        "principalId": "A3GISO2WDBCEWM"
                    },
                    "arn": "arn:aws:s3:::vg-diy-bucket-dev-diybucket-1qxql8dgn091j"
                },
                "object": {
                    "key": "alpha/a-company/input/tom4.sketch",
                    "size": 15997,
                    "eTag": "d85418441fdbc7a8efa742636e5b307f",
                    "sequencer": "005B7AD468280AB67F"
                }
            }
        }
    ]
}

context:
{
    "callbackWaitsForEmptyEventLoop": true,
    "logGroupName": "/aws/lambda/vg-diy-bucket-dev-transformOnBucketUpload",
    "logStreamName": "2018/08/20/[$LATEST]537980e1087f4a4bbf7e5aec2969b978",
    "functionName": "vg-diy-bucket-dev-transformOnBucketUpload",
    "memoryLimitInMB": "512",
    "functionVersion": "$LATEST",
    "invokeid": "e74e2acf-a487-11e8-a4bc-75bebe154b8e",
    "awsRequestId": "e74e2acf-a487-11e8-a4bc-75bebe154b8e",
    "invokedFunctionArn": "arn:aws:lambda:us-east-1:086312920481:function:vg-diy-bucket-dev-transformOnBucketUpload"
}


END RequestId: e74e2acf-a487-11e8-a4bc-75bebe154b8e
REPORT RequestId: e74e2acf-a487-11e8-a4bc-75bebe154b8e	Duration: 4.78 ms	Billed Duration: 100 ms Memory Size: 512 MB	Max Memory Used: 231 MB

• What did you expect should have happened?

The lambda should not end the request after logging the context. It should also log generated project files...

• What was the config you used?

webpack.config.js

const path = require('path')
const slsw = require('serverless-webpack')
const nodeExternals = require('webpack-node-externals')
const TsconfigPathsPlugin = require('tsconfig-paths-webpack-plugin')

const entries = {}

Object.keys(slsw.lib.entries).forEach(
  key => (entries[key] = ['./source-map-install.js', slsw.lib.entries[key]])
)

module.exports = {
  mode: slsw.lib.webpack.isLocal ? 'development' : 'production',
  optimization: {
		minimize: false
	},
  entry: entries,
  // We use webpack-node-externals to excludes all node deps.
  // You can manually set the externals too.
  externals: [nodeExternals()],
  devtool: 'source-map',
  resolve: {
    plugins: [
      new TsconfigPathsPlugin({ configFile: './tsconfig.json' })
    ],
    extensions: ['.js', '.jsx', '.json', '.ts', '.tsx']
  },
  output: {
    libraryTarget: 'commonjs',
    path: path.join(__dirname, '.webpack'),
    filename: '[name].js'
  },
  target: 'node',
  module: {
    rules: [
      // all files with a `.ts` or `.tsx` extension will be handled by `ts-loader`
      { test: /\.tsx?$/, loader: 'ts-loader', options: { configFile: 'tsconfig.json' } }
    ]
  }
}

serverless.yml

custom:
  userFolderName: alpha
  webpack:
    packager: yarn
    
    # enable auto-packing of external modules
    includeModules:
      # see https://github.com/serverless-heaven/serverless-webpack/issues/435
      forceExclude:
        - aws-sdk
        - prettier

(see also #435)

tsconfig.json:

{
  "extends": "../../tsconfig.json",
  "compilerOptions": {
    "rootDir": "src",
    "sourceMap": true,
    "target": "es6",
    "lib": ["esnext", "dom"],
    "moduleResolution": "node",
    // Lambda does not benefit from declaration files
    "declaration": false,
    // Workaround issue where tsconfig-paths does not pick up
    // Relative baseUrl from yarn root workspace
    "baseUrl": "../"
  },
  "exclude": ["node_modules", "dist"]
}

.../../tsconfig.json:

{
  "extends": "./tsconfig.base.json",
  "compilerOptions": {
    "baseUrl": "./packages",
    "paths": {
      "*": ["./*/src"]
    }
  }
}

../../tsconfig.base.json:

{
  "compilerOptions": {
    "target": "es2017",
    "module": "commonjs",
    "lib": ["es2017", "dom"],
    "typeRoots": ["./node_modules/@types", "./packages/types/src/external"],
    "declaration": true,
    "strict": true,
    "esModuleInterop": true,
    "forceConsistentCasingInFileNames": true,
    "noImplicitAny": true,
    "strictNullChecks": true,
    "noImplicitThis": true,
    "alwaysStrict": true,
    "noUnusedLocals": true,
    "noUnusedParameters": true,
    "noImplicitReturns": true,
    "noFallthroughCasesInSwitch": true
  },
  "exclude": ["node_modules", "dist"]
}

I've also tried it with tsconfig.json:

{
  "extends": "../../tsconfig.base.json",
  "compilerOptions": {
    "rootDir": "src",
    "outDir": "dist"
  },
  "exclude": ["test", "node_modules", "dist"]
}

But the effect is the same. Note that I am using yarn workspaces (see this repo for an example)

• What stacktrace or error message from your provider did you see?

see above for the cloudwatch log

Note that when I run it locally the behavior is the same:

Toms-MacBook-Pro-2:serverless-diy-bucket tommedema$ npx serverless invoke local --function transformOnBucketUpload --path ./test/mocks/s3-create-event.json
Serverless: DOTENV: Loading environment variables:
Serverless:      - DIY_BUCKET_ADMIN_PASSWORD
Serverless: Bundling with Webpack...
Time: 22773ms
Built at: 2018-08-20 12:14:52
               Asset      Size         Chunks             Chunk Names
    src/transform.js  12.7 MiB  src/transform  [emitted]  src/transform
src/transform.js.map    13 MiB  src/transform  [emitted]  src/transform
Entrypoint src/transform = src/transform.js src/transform.js.map
[../../node_modules/aws-sdk/clients/all.js] /Users/my-project/node_modules/aws-sdk/clients/all.js 5.57 KiB {src/transform} [built]
[../../node_modules/aws-sdk/lib/aws.js] /Users/my-project/node_modules/aws-sdk/lib/aws.js 159 bytes {src/transform} [built]
[../../node_modules/aws-sdk/lib/core.js] /Users/my-project/node_modules/aws-sdk/lib/core.js 2.17 KiB {src/transform} [built]
[../../node_modules/buffer-from/index.js] /Users/my-project/node_modules/buffer-from/index.js 1.56 KiB {src/transform} [built]
[../../node_modules/source-map-support/source-map-support.js] /Users/my-project/node_modules/source-map-support/source-map-support.js 17.5 KiB {src/transform} [built]
[0] multi ./source-map-install.js ./src/transform.ts 40 bytes {src/transform} [built]
[../vgcli/node_modules/execa/index.js] 7.54 KiB {src/transform} [built]
[../vgcli/src/index.ts] 4.62 KiB {src/transform} [built]
[./source-map-install.js] 40 bytes {src/transform} [built]
[./src/transform.ts] 4.1 KiB {src/transform} [built]
[fs-extra] external "fs-extra" 42 bytes {src/transform} [built]
[module] external "module" 42 bytes {src/transform} [optional] [built]
[path] external "path" 42 bytes {src/transform} [built]
[util] external "util" 42 bytes {src/transform} [built]
[uuid/v4] external "uuid/v4" 42 bytes {src/transform} [built]
    + 1384 hidden modules

WARNING in /Users/my-project/node_modules/prettier/index.js 7103:15-64
Critical dependency: the request of a dependency is an expression
 @ ../grid-to-react/src/projectFiles.ts
 @ ../grid-to-react/src/index.ts
 @ ../vgcli/src/index.ts
 @ ./src/transform.ts
 @ multi ./source-map-install.js ./src/transform.ts

WARNING in /Users/my-project/node_modules/prettier/index.js 28458:7-46
Critical dependency: the request of a dependency is an expression
 @ ../grid-to-react/src/projectFiles.ts
 @ ../grid-to-react/src/index.ts
 @ ../vgcli/src/index.ts
 @ ./src/transform.ts
 @ multi ./source-map-install.js ./src/transform.ts

WARNING in /Users/my-project/node_modules/prettier/third-party.js 4143:15-32
Critical dependency: the request of a dependency is an expression
 @ /Users/my-project/node_modules/prettier/index.js
 @ ../grid-to-react/src/projectFiles.ts
 @ ../grid-to-react/src/index.ts
 @ ../vgcli/src/index.ts
 @ ./src/transform.ts
 @ multi ./source-map-install.js ./src/transform.ts

WARNING in /Users/my-project/node_modules/prettier/parser-glimmer.js 1:128755-128773
require.extensions is not supported by webpack. Use a loader instead.
 @ /Users/my-project/node_modules/prettier/index.js 28347:13-40
 @ ../grid-to-react/src/projectFiles.ts
 @ ../grid-to-react/src/index.ts
 @ ../vgcli/src/index.ts
 @ ./src/transform.ts
 @ multi ./source-map-install.js ./src/transform.ts

WARNING in /Users/my-project/node_modules/prettier/parser-glimmer.js 1:128776-128794
require.extensions is not supported by webpack. Use a loader instead.
 @ /Users/my-project/node_modules/prettier/index.js 28347:13-40
 @ ../grid-to-react/src/projectFiles.ts
 @ ../grid-to-react/src/index.ts
 @ ../vgcli/src/index.ts
 @ ./src/transform.ts
 @ multi ./source-map-install.js ./src/transform.ts

WARNING in /Users/my-project/node_modules/prettier/parser-glimmer.js 1:128813-128831
require.extensions is not supported by webpack. Use a loader instead.
 @ /Users/my-project/node_modules/prettier/index.js 28347:13-40
 @ ../grid-to-react/src/projectFiles.ts
 @ ../grid-to-react/src/index.ts
 @ ../vgcli/src/index.ts
 @ ./src/transform.ts
 @ multi ./source-map-install.js ./src/transform.ts
Serverless: INVOKING INVOKE

    onBucketUpload fired with:

    event: {"Records":[{"eventVersion":"2.0","eventSource":"aws:s3","awsRegion":"us-east-1","eventTime":"2018-08-15T17:31:15.647Z","eventName":"ObjectCreated:Put","userIdentity":{"principalId":"A3GISO2WDBCEWM"},"requestParameters":{"sourceIPAddress":"177.79.43.217"},"responseElements":{"x-amz-request-id":"BCA7678624F6D091","x-amz-id-2":"C1eGFMv/B27qrMjDpOb2/0RsYLGZZf5Q+dHcYTcrNTKTUCi/1IU9CpiRDJeA6CODap7CdfJhiqs="},"s3":{"s3SchemaVersion":"1.0","configurationId":"ec6e73bf-3734-4c60-819a-917e562e5f54","bucket":{"name":"vg-diy-bucket-dev-diybucket-1qxql8dgn091j","ownerIdentity":{"principalId":"A3GISO2WDBCEWM"},"arn":"arn:aws:s3:::vg-diy-bucket-dev-diybucket-1qxql8dgn091j"},"object":{"key":"alpha/a-company/input/test.sketch","size":15997,"eTag":"d85418441fdbc7a8efa742636e5b307f","sequencer":"005B746363935A872A"}}}]}
    context: {"awsRequestId":"id","invokeid":"id","logGroupName":"/aws/lambda/vg-diy-bucket-dev-transformOnBucketUpload","logStreamName":"2015/09/22/[HEAD]13370a84ca4ed8b77c427af260","functionVersion":"HEAD","isDefaultFunctionVersion":true,"functionName":"vg-diy-bucket-dev-transformOnBucketUpload","memoryLimitInMB":"1024"}

Additional Data

• Serverless-Webpack Version you're using:
  5.2.0

• Webpack version you're using:
  4.16.5

• Serverless Framework Version you're using:
  Serverless Version: 1.30.0

• Operating System:
  OS: darwin
  Node Version: 8.11.3

[HyperBrain]

Hi @tommedema . This looks like the AWS Lambda runtime isn't awaiting the returned function (which internally is a promise).

This does not seem to be an issue with webpack or the plugin in general, but more likely with TS or the resolver, as everything looks good in the configuration.

According to https://aws.amazon.com/blogs/compute/node-js-8-10-runtime-now-available-in-aws-lambda/ someting like

exports.handler = async (event) => {
    return await lambda.getAccountSettings().promise() ;
};

should work. I'm not sure if the __awaiter() function, generated by TS behaves the same. Is there any way to configure the TS resolver to emit Node 8 (async/await) compatible code that includes the async keyword? Alternatively you could try to add the 3rd lambda parameter (the callback) and experimentally await locally in the function and call the callback.
Can you try that and report back, what happened? This is a quite interesting thing.

[tommedema]

@HyperBrain you are correct that it is not related to webpack, sorry about that.

Turns out that one of the promises was rejected but I didn't register a handler for this. I had to encapsulate all promises with try { } catch { } .