-
Notifications
You must be signed in to change notification settings - Fork 43
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
NR node lambda layer doesn't initialize function when using Provisioned Concurrency & fails to find handler when exported within promise #185
Comments
Expected behaviour with newrelic lambda layerWe expect newrelic lambda layer to also initialize function as well similar to AWS does when not using the layer. When first/second request is received there should not be any time spent on initialization if provisioned concurrency is enabled. ESM & CommonJS
Expected Provisioned Concurrency Initialization log (6.43 seconds)--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| timestamp | message |
|---------------|--------------------------------------------------------------------------------------------------------------------------------------------------------------------|
| 1697506821075 | INIT_START Runtime Version: nodejs:18.v13 Runtime Version ARN: arn:aws:lambda:us-east-1::runtime:98792929c89e9ef325cbf51e2dd60dd8cfb8a23a70f14859c5609e9c9ae8a094 |
| 1697506822128 | [NR_EXT] New Relic Lambda Extension starting up |
| 1697506822188 | [NR_EXT] Extension telemetry processing disabled |
| 1697506822188 | [NR_EXT] Starting no-op mode, no telemetry will be sent |
| 1697506824468 | 2023-10-17T01:40:24.468Z undefined INFO 1697506824468: start init |
| 1697506827473 | 2023-10-17T01:40:27.473Z undefined INFO 1697506827472: end init |
| 1697506827508 | EXTENSION Name: newrelic-lambda-extension State: Ready Events: [INVOKE, SHUTDOWN] |
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- Expected First Request with Provisioned Concurrency log (35.30 ms)-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| timestamp | message |
|---------------|-------------------------------------------------------------------------------------------------------------------------------------------------------------------------|
| 1697507059577 | START RequestId: 7b2656de-ffc7-4aea-86c0-aa9773383255 Version: 14 |
| 1697507059578 | 2023-10-17T01:44:19.578Z 7b2656de-ffc7-4aea-86c0-aa9773383255 INFO 1697507059578: executing handler |
| 1697507059590 | [1,"NR_LAMBDA_MONITORING","H4sIAAAAAAAAA+1XW3PaRhT+Kx09g7T3i94cx67dSVJPcJIHT4ZZpDWoEZKyWtkmHv57jyRwTQLEl6TNQ80YlmX1ne9c95zbYG69SY03QXwbGFcEcfsem="] |
| 1697507059612 | END RequestId: 7b2656de-ffc7-4aea-86c0-aa9773383255 |
| 1697507059612 | REPORT RequestId: 7b2656de-ffc7-4aea-86c0-aa9773383255 Duration: 35.30 ms Billed Duration: 36 ms Memory Size: 128 MB Max Memory Used: 80 MB Init Duration: 6453.34 ms |
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- Expected Second Request with Provisioned Concurrency log (68.57 ms)-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| timestamp | message |
|---------------|-------------------------------------------------------------------------------------------------------------------------------------------------------------------------|
| 1697507121784 | START RequestId: 90e64430-d4db-49b3-a05e-8a196e81d4f1 Version: 14 |
| 1697507121813 | 2023-10-17T01:45:21.813Z 90e64430-d4db-49b3-a05e-8a196e81d4f1 INFO 1697507121813: executing handler |
| 1697507121825 | [1,"NR_LAMBDA_MONITORING","H4sIAAAAAAAAA+1X23LiOBD9lS0/g5Bk3ey3TC6bVGWmUgvZeUhNUcIW4B1js7JMwqT4920ZyMKEy+YyMy"] |
| 1697507121853 | END RequestId: 90e64430-d4db-49b3-a05e-8a196e81d4f1 |
| 1697507121853 | REPORT RequestId: 90e64430-d4db-49b3-a05e-8a196e81d4f1 Duration: 68.57 ms Billed Duration: 69 ms Memory Size: 128 MB Max Memory Used: 81 MB |
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- |
Thank you for the report and the repro case, @p-nikul . We'll investigate. |
Hi, is there any update on this ask ? Without this support using Provision concurrency with node.js newrelic lambda layers is not useful at all. It is blocking us to fully utilize newrelic in Production. |
Hello @p-nikul, We've thoroughly reviewed the bug and the AWS documentation link you provided. After examining the sample code, we successfully identified the issue. Interestingly, when we bypassed the main function and directly used the top-level handler as per the document, it worked as expected. We also observed a notable optimization: when running the code for the second or third time, the total duration is significantly reduced since the init function only executes during the first run. Please find the code snippet below for your reference:
const sleep = ms => new Promise(resolve => setTimeout(resolve, ms));
async function init() {
console.log(`${Date.now()}: start init`);
await sleep(3000);
console.log(`${Date.now()}: end init`);
}
const initPromise = init();
async function handler(event, context) {
await initPromise;
console.log(`${Date.now()}: executing handler`);
return {
body: 'foo',
statusCode: 200,
};
}
module.exports.handler = handler; Could you please confirm whether it works for you as well? If you encounter any issues or have feedback on the implementation, we'd love to hear about it. |
arn:aws:lambda:us-east-1:451483290750:layer:NewRelicNodeJS20X:39
arn:aws:lambda:us-east-1:451483290750:layer:NewRelicNodeJS20X:39
@aavinash-nr Main difference when using suggested code by you init function is not called until handler is triggered. So when using provisioned concurrency init function is not initialized until first event trigger handler. End goal here is able to initialize function without calling/triggering handler when using Provisioned concurrency and reduce cold start time. Logs with layer and provisioned concurrency with suggested code
With below code snippet (without NR layer) I'm able to initialize my function without needing of handler getting triggered/called with AWS lambda
|
Hello @p-nikul, To reduce first run duration you could utilize layerless approach. |
Work has been completed on this issue. |
Description
When instrumenting node lambda function using the newrelic lambda layer, the layer wrapper doesn't initialize function before first request is received. This behaviour is the same even when we turn on Provisioned Concurrency, it initializes the newrelic lambda extension but doesn't initialize the function wrapped with newrelic-lambda-wrapper.handler.
Top level await Blog by AWS : Link
Related issue: We can minimize cold start with provisioned concurrency for CommonJS via initializing function first and exporting handler via Promise. This works on AWS Lambda without newrelic wrapper but fails when we use newrelic lambda wrapper
Issues:
When module exports Promise which resolves handler wrapper fails to find handler. An AWS Lambda without the newrelic lambda layer works fine
When using newrelic node lambda layer, it doesn't initialize function init code. This affects usage of provisioned concurrency.
Example handler code ESM
Example handler code CommonJS
Behaviour without Newrelic lambda layer
Provisioned Concurrency Initialization log (5.35 seconds)
First Request with Provisioned Concurrency log (9.30 ms)
Second Request with Provisioned Concurrency log (1.60 ms)
Steps to Reproduce (with newrelic lambda layer)
commonjs
Provisioned Concurrency Initialization log (9.30 seconds)
Request Failed (400.31 ms)
ESM
Provisioned Concurrency initialization log (9.45 seconds)
First Request with Provisioned Concurrency log (3.68 seconds)
Second Request log (7 ms)
Expected behaviour with newrelic lambda layer
See below comment #185 (comment)
Relevant Logs / Console output
See below comment #185 (comment)
The text was updated successfully, but these errors were encountered: