Lambda extensions blocking rust lambdas?

[xorxsan]

So I started my first lambda (function url) in Rust and wanted to add the Newrelic Lambda Extension (arn:aws:lambda:eu-west-1:451483290750:layer:NewRelicLambdaExtension:51) to send logs and telemetry to Newrelic.

I used a fairly simple code (very much like the ones in the examples):

pub async fn function_handler(
    request: lambda_http::Request,
) -> Result<lambda_http::Response<lambda_http::Body>, lambda_runtime::Error> {
    Ok(lambda_http::Response::builder()
        .status(200)
        .header("Content-Type", "application/json")
        .body(lambda_http::Body::from("A Test"))?)
}

#[tokio::main]
async fn main() -> Result<(), lambda_runtime::Error> {
    tracing_subscriber::fmt()
        .with_max_level(tracing::Level::INFO)
        .without_time()
        .with_ansi(false)
        .json()
        .init();

    tracing::info!("Handler execution started.");

    lambda_http::run(lambda_http::service_fn(
        function_handler,
    ))
    .await
}

The lambda is configured with 2 minutes timeout and a reserved concurrency of 2.

When I call the lambda url I can only call it twice. However if I remove the extension layer, then I can call the lambda as many times as I want.

If I unset the reserved concurrency and make five requests I get the below pattern 5 times:

INIT_START Runtime Version: provided:al2023.v93 Runtime Version ARN: arn:aws:lambda:eu-west-1::runtime:520452c01f1d6aaabcad19c6c2986c22188b1d50daeb583ec6dee8adf883fb62
REPORT RequestId: idx Duration: 119824.00 ms Billed Duration: 120086 ms Memory Size: 128 MB Max Memory Used: 42 MB Init Duration: 261.35 ms
END RequestId: idx
[NR_EXT] Extension shutdown after 468591ms

It is not clear to me why it always takes 2 minutes when the layer is configured. I'm probably missing something, but I don't know what.

Thanks for your help.

[bnusunny]

This looks like an issue with Newrelic Lambda extension. You probably need to check their document to properly configure the extension.

[xorxsan]

I will open a request on their repo, but this extension is working on other lambdas written in golang. That's why I thought it might be an issue with lambdas written in Rust.

[jlizen]

@xorxsan -

Background

With the function code you shared, it's hard to imagine that the rust lambda runtime has much to do with the delay. Since, the lambda execution environment runs both the rust runtime and the external extension in separate processes and signals them to process events simultaneously.

So, the execution environment will process the function handler right away and return a response to the caller when it completes. In parallel, the invocation continues until all extensions as well as the function handler complete, or there is a timeout.

The function handler and extension handler communicate only indirectly through language agnostic http apis mediated by the lambda execution environment - the main execution environment API moves them between phases and triggers events, and the telemetry API allows the extension to hook into function telemetry as collected by the execution environment.

More information.

Confirm your rust function is behaving properly

It's possible that there is something else going on within your rust code causing it to hang, but your code sample seems fairly innocent.

If you wanted to double check, you could add some log lines at the start and end of your function handler (assuming you have your function configured to publish logs to cloudwatch and not just new relic via extension). We would expect to see it fire and quickly end, and then the remaining delay not show up on the rust application layer timings since lambda is only waiting for your external extension to complete before ending the invocation.

We would also expect the function handler response to return to the caller immediately, even if the external extension is hanging, so you could use cargo lambda income --remote, test in console, or otherwise invoke the lambda and see if you get a quicker response than the ultimate invocation timeout.

Investigate extension-side issues

Assuming that you've confirmed that the function handler is returning properly, and the extension is hanging:

It is possible that your extension is being configured to wait on some signal using the lambda extension telemetry API that is never coming, or some other misconfiguration. I would look at how what sorts of telemetry your go lambdas functions are emitting that the simple rust lambda might not be (or any differences in extension configuration).

That might be a more useful investigation to dig into in the new relic issue if you can establish that the lambda function handler is returning properly, since we aren't very familiar with the extension's usage. Though, glad to offer perspective where relevant if you want to tag me into that issue.

[xorxsan]

Hi @jlizen thanks for your response. Maybe I've misunderstood how extensions and lambdas work together. I had the impression that once a lambda finishes its execution everything is tear down after some time (just in case another invocation is coming and could be served by the same runtime environment). In fact this is what it looks like it's happening when I remove the NewRelicExentsionLayer.

You said:

We would expect to see it fire and quickly end, and then the remaining delay not show up on the rust application layer timings since lambda is only waiting for your external extension to complete before ending the invocation.

I've downloaded the logs from cloudwatch and they look like this:

CloudWatch Logs Insights
region: eu-west-1
log-group-names: /aws/lambda/my-rust-lambda
start-time: -300s
end-time: 0s
query-string:

fields @timestamp, @message, @log
| sort @timestamp desc
| limit 10000

---

@timestamp	@message	@log
2025-07-18 09:45:55.990	[NR_EXT] Sent 1/1 New Relic Telemetry payload batches with 1 log events successfully with certainty in 150.996ms (150ms to transmit 0.4kB).	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:45:55.990	[NR_EXT] Extension shutdown after 809828ms	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:45:55.839	[NR_EXT] Log server started to terminate: http: Server closed	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:45:55.820	[NR_EXT] New Relic Extension shutting down after 2 events	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:40:56.116	[NR_EXT] Sent 1/1 New Relic Telemetry payload batches with 1 log events successfully with certainty in 268.480ms (267ms to transmit 0.4kB).	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:40:56.116	[NR_EXT] Extension shutdown after 487976ms	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:40:55.828	[NR_EXT] New Relic Extension shutting down after 2 events	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:40:55.828	[NR_EXT] Log server started to terminate: http: Server closed	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:34:48.157	END RequestId: c595d0b7-86fe-4bf6-bea9-a3e0be60c080	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:34:48.157	REPORT RequestId: c595d0b7-86fe-4bf6-bea9-a3e0be60c080 Duration: 119823.41 ms Billed Duration: 120108 ms Memory Size: 128 MB Max Memory Used: 59 MB Init Duration: 284.31 ms	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:34:26.179	END RequestId: e8acc376-527c-4763-af6c-dc076b97df9f	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:34:26.179	REPORT RequestId: e8acc376-527c-4763-af6c-dc076b97df9f Duration: 119823.27 ms Billed Duration: 120116 ms Memory Size: 128 MB Max Memory Used: 60 MB Init Duration: 292.68 ms	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:50.148	[NR_EXT] Sent 1/1 New Relic function log batches successfully with certainty in 112.001ms (110ms to transmit 0.5kB).	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:49.508	{"level":"INFO","fields":{"message":"Successfully sent response."},"target":"my-lambda::handler","span":{"requestId":"c595d0b7-86fe-4bf6-bea9-a3e0be60c080","xrayTraceId":"Root=1-687a14bf-5e1e4103796882b41a8138a5;Parent=2064bc9d0b389a69;Sampled=0;Lineage=1:b9775858:0","name":"Lambda runtime invoke"},"spans":[{"requestId":"c595d0b7-86fe-4bf6-bea9-a3e0be60c080","xrayTraceId":"Root=1-687a14bf-5e1e4103796882b41a8138a5;Parent=2064bc9d0b389a69;Sampled=0;Lineage=1:b9775858:0","name":"Lambda runtime invoke"}]}	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:49.026	[NR_EXT] Sent 1/1 New Relic function log batches successfully with certainty in 177.128ms (176ms to transmit 0.3kB).	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:48.334	START RequestId: c595d0b7-86fe-4bf6-bea9-a3e0be60c080 Version: $LATEST	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:48.333	EXTENSION Name: newrelic-lambda-extension State: Ready Events: [INVOKE, SHUTDOWN]	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:48.331	LOGS Name: newrelic-lambda-extension State: Subscribed Types: [Platform, Function]	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:48.330	[NR_EXT] Starting log server.	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:48.250	{"level":"INFO","fields":{"message":"Handler execution started."},"target":"my_rust_lambda"}	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:48.143	[NR_EXT] New Relic Lambda Extension starting up	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:48.143	[NR_EXT] Initializing version 2.3.20 of the New Relic Lambda Extension...	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:48.049	INIT_START Runtime Version: provided:al2023.v100 Runtime Version ARN: arn:aws:lambda:eu-west-1::runtime:xxxxxxxxxx	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:28.379	[NR_EXT] Sent 1/1 New Relic function log batches successfully with certainty in 220.001ms (218ms to transmit 0.5kB).	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:27.560	{"level":"INFO","fields":{"message":"Successfully sent response."},"target":"my-lambda::handler","span":{"requestId":"e8acc376-527c-4763-af6c-dc076b97df9f","xrayTraceId":"Root=1-687a14a9-7ae389b95760ef126de7506f;Parent=2ffe290454e098c7;Sampled=0;Lineage=1:b9775858:0","name":"Lambda runtime invoke"},"spans":[{"requestId":"e8acc376-527c-4763-af6c-dc076b97df9f","xrayTraceId":"Root=1-687a14a9-7ae389b95760ef126de7506f;Parent=2ffe290454e098c7;Sampled=0;Lineage=1:b9775858:0","name":"Lambda runtime invoke"}]}	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:27.072	[NR_EXT] Sent 1/1 New Relic function log batches successfully with certainty in 215.461ms (214ms to transmit 0.3kB).	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:26.356	START RequestId: e8acc376-527c-4763-af6c-dc076b97df9f Version: $LATEST	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:26.355	EXTENSION Name: newrelic-lambda-extension State: Ready Events: [INVOKE, SHUTDOWN]	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:26.354	LOGS Name: newrelic-lambda-extension State: Subscribed Types: [Platform, Function]	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:26.353	[NR_EXT] Starting log server.	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:26.265	{"level":"INFO","fields":{"message":"Handler execution started."},"target":"my_rust_lambda"}	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:26.163	[NR_EXT] New Relic Lambda Extension starting up	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:26.163	[NR_EXT] Initializing version 2.3.20 of the New Relic Lambda Extension...	12345678910:/aws/lambda/my-rust-lambda
2025-07-18 09:32:26.063	INIT_START Runtime Version: provided:al2023.v100 Runtime Version ARN: arn:aws:lambda:eu-west-1::runtime:xxxxxxxxxx	12345678910:/aws/lambda/my-rust-lambda

---

As you can see there are two INIT_START (so two cold starts seconds apart) and, due to my lambda's reserved concurrency set to 2, subsequent calls are throttled ( An error occurred (TooManyRequestsException) when calling the Invoke operation (reached max retries: 2): Rate Exceeded.).

As I see from the extension logs (prefixed by [NR_EXT]), the extension seems to be waiting for the SHUTDOWN event which seems to come after the lambda times out (2 minutes later). And then, I can invoke again.

What I don't understand is why subsequent requests do not use the same runtime environment (I'm invoking them by hand from the aws-cli, so I need to wait for the lambad's response, which comes after a couple of seconds, before sending another request).

I'll see if my go lambdas are sending some event to the telemetry API so the NewRelicLambdaLayer unblocks the lambda so it can get more requests.

Thanks!

[jlizen]

I had the impression that once a lambda finishes its execution everything is tear down after some time (just in case another invocation is coming and could be served by the same runtime environment). In fact this is what it looks like it's happening when I remove the NewRelicExentsionLayer.

That is accurate, if a lambda doesn't receive traffic for a (non-deterministic) period of time, the lambda execution environment will send shutdown signals to it and all of its configured extensions. Until then, the runtime and extensions will continue listening for new invocations (via the /next api).

Though, that's not the whole story - extensions also relate to the invocation phase. Essentially an invocation signal is sent both to the primary handler and all extensions registered for the current phase via the /next API. They all can complete their processing separately, including the runtime handler returning a response to the caller, but the overall invocation is considered ongoing until both the handler and the extensions make a new /next call on the lambda execution environment. Ref

Your logs seem to show the function handler completing very quickly (~1 ms). You don't explicitly capture it calling /next, but I see no reason to assume an issue there as your code is very simple and all Rust lambdas would break if that didn't happen following returning the invocation response.

Your logs are a bit muddied since they are showing multiple executions running on separate lambda instances. If you include the log stream field, it will be more apparent, since each separate lambda instance will write to a different log stream.

Anyway, the behavior is as expected - the function handler returns right away, but the overall invocation takes an extra two minutes. This extra two minutes is because the invocation is waiting for the extension to signal completion. Because the invocation isn't signalling completion, the invocation is considered ongoing, and further invocations involve spinning up new runtime instances, eventually reaching your concurrency limit.

So the question to answer is, why is the extension hanging on invocation rather than successfully ending and calling /next. Perhaps it is waiting on some signals on from the runtime handler that aren't coming? Perhaps the configuration is different compared to Go? This would be a good question for the extension authors.

[jlizen]

One thing to note from the docs:

To help identify the performance impact introduced by extensions on the Invoke phase, Lambda outputs the PostRuntimeExtensionsDuration metric. This metric measures the cumulative time spent between the runtime Next API request and the last extension Next API request. [...] For more information about function metrics, see Using CloudWatch metrics with Lambda.

You could take a look at that metric to confirm the above explanation.

[xorxsan]

I'm going to close this ticket because it turns out that the extension I'm using does not support rust.

Thanks for your help!

[github-actions]

This issue is now closed. Comments on closed issues are hard for our team to see.
If you need more assistance, please either tag a team member or open a new issue that references this one.