CODEWITHSUNDEEP
amazon-web-servicesaws-lambda
murty
murty

Reputation: 145

Lambda duration > 10x longer than expected

In the below example, I have an AWS Lambda function (written in Node) where the business logic is executed in 60ms, yet the full duration is 794ms.

23:49:19 START RequestId: d1110932-2586-11e8-8d80-f74f5d6cf7b8 Version: $LATEST
23:49:20 2018-03-11T23:49:20.559Z   d1110932-2586-11e8-8d80-f74f5d6cf7b8    Start of Lambda: 1520812160559
...
23:49:20 2018-03-11T23:49:20.619Z   d1110932-2586-11e8-8d80-f74f5d6cf7b8    End of Lambda 1520812160619
23:49:20 END RequestId: d1110932-2586-11e8-8d80-f74f5d6cf7b8
23:49:20 REPORT RequestId: d1110932-2586-11e8-8d80-f74f5d6cf7b8 Duration: 794.57 ms Billed Duration: 800 ms Memory Size: 128 MB Max Memory Used: 52 MB

I'm confused as to why the function is taking so long to execute given that everything inside the handler executes in 60ms.

Some notes:

Is there any way to investigate / reduce this duration? Is it common to see so much of a Lambda's execution attributed to startup time, even on subsequent executions?

Relevant code:

export const getPublishedLessons = async (event, context, callback) => {
  // establish inside of handler to avoid extra db connections
  const lessonService = new LessonService()
  try {
    const results = await lessonService.getLessonsByFilter({ isPublished: true })
    console.error('End of Lambda', moment().valueOf())
    return respond(callback, results)
  } catch(err) {
    console.error(`Error in lessonHandler.getManyLessons: [${err}]`)
    return fail(callback, err)
  }
}


const eventWrapper = async (event, context, callback, eventFunction) => {
  console.error('Start of Lambda: ', moment().valueOf())
  context.callbackWaitsForEmptyEventLoop = false
  if(event.source === 'serverless-plugin-warmup') {
    // ensure db connection
    await mongoFactory.getConnection(process.env.MONGO_URI, process.env.MONGO_DB_NAME)
    const mongoService = new MongoService()
    await mongoService.createIndexes('Lessons', [ _idIndex, lessonIdIndex ], indexOptions)
    await mongoService.createIndexes('LessonThemes', [ _idIndex ], indexOptions)
    await mongoService.createIndexes('LessonMetadata', [ typeIndex ], indexOptions)
    await mongoService.createIndexes('Messages', [ _idIndex ], indexOptions)
    await mongoService.createIndexes('PasswordRecovery', [ _idIndex ], indexOptions)
    await mongoService.createIndexes('Profiles', [ _idIndex ], indexOptions)
    await mongoService.createIndexes('UserLessons', [ _idIndex, lessonIdIndex, userIdIndex ], indexOptions)
    await mongoService.createIndexes('UserProjects', [ _idIndex, userIdIndex ], indexOptions)
    console.log('WarmUP - Lambda is warm!')
    return callback(null, 'Lambda is warm!')
  }
  if(event.body && isString(event.body))
    event.body = JSON.parse(event.body)
  return await eventFunction(event, context, callback)
}

module.exports.getPublishedLessonsHandler = (...params) => eventWrapper(...params, getPublishedLessons)

Upvotes: 0

Views: 924

Answers (1)

murty
murty

Reputation: 145

Answering my own question based on information found here:

My Lambda's RAM was configured to 128mb and my execution times were anywhere from ~100ms to ~1s, even with a reused container.

After increasing RAM to 1536mb, my execution times are consistently well under 100ms. 1536mb is obviously much more expensive per millisecond, but I expect that my overall price won't increase dramatically given the reduced execution time.

Upvotes: 1

Related Questions