Skip to content

Commit 87277be

Browse files
committed
feat(tracing, docs): add support for custom writer with default tracing subscriber, add graceful shutdown example using a non-blocking writer
1 parent c511046 commit 87277be

File tree

4 files changed

+197
-3
lines changed

4 files changed

+197
-3
lines changed

examples/graceful-shutdown/Cargo.toml

+12
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,12 @@
1+
[package]
2+
name = "graceful-shutdown"
3+
version = "0.1.0"
4+
edition = "2021"
5+
6+
[dependencies]
7+
anyhow = "1"
8+
lambda-extension = { path = "../../lambda-extension" }
9+
lambda_runtime = { path = "../../lambda-runtime" }
10+
serde = "1.0.136"
11+
tokio = { version = "1", features = ["macros", "signal"] }
12+
tracing-appender = "0.2"

examples/graceful-shutdown/README.md

+40
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,40 @@
1+
# AWS Lambda runtime example for graceful shutdown
2+
3+
This example demonstrates how to build an AWS Lambda function that handles a graceful shutdown signal
4+
from the lambda runtime. In our case, we use it to flush any outstanding log entries from a
5+
[tracing_appender::NonBlocking](https://docs.rs/tracing-appender/latest/tracing_appender/non_blocking/struct.NonBlocking.html) dedicated logging thread.
6+
7+
Note that in order to receive graceful shutdown signals, an internal or external Lambda extension must be registered. See [the official documentation](https://docs.aws.amazon.com/lambda/latest/dg/lambda-runtime-environment.html#runtimes-lifecycle-shutdown) for more information on the `Shutdown` phase.
8+
9+
In this example, we register a dummy [internal extension](https://docs.aws.amazon.com/lambda/latest/dg/runtimes-extensions-api.html), which gets us 500ms of graceful shutdown time. You could also include a useful internal extension, such as demonstrated in `../extension-internal-flush`.
10+
11+
Another common approach would be to use the [CloudWatch Lambda Insights external extension](https://docs.aws.amazon.com/lambda/latest/dg/monitoring-insights.html), in which case you can omit the internal extension. Note that this will incur additional billing charges, though it provides
12+
useful telemetry. For a complete example using Lambda Insights, see [this aws-samples example](https://github.com/aws-samples/graceful-shutdown-with-aws-lambda/tree/main/rust-demo).
13+
14+
## Build & Deploy
15+
16+
1. Install [cargo-lambda](https://github.com/cargo-lambda/cargo-lambda#installation)
17+
2. Build the function with `cargo lambda build --release`
18+
3. Deploy the function to AWS Lambda with `cargo lambda deploy --iam-role YOUR_ROLE`
19+
20+
## Build for ARM 64
21+
22+
Build the function with `cargo lambda build --release --arm64`
23+
24+
## Test your Function
25+
26+
Note that `cargo lambda watch` does not currently send graceful shutdown signals to your function, so this is difficult to test locally.
27+
Ref: https://github.com/cargo-lambda/cargo-lambda/issues/850
28+
29+
If you have deployed to AWS using the above commands you can invoke your function remotely
30+
```
31+
cargo lambda invoke graceful-shutdown --remote --data-ascii '{"command": "hello"}'
32+
```
33+
34+
AWS might take some time before it shuts your function down after invocation, particularly during off-peak hours. But, if you wait long enough,
35+
you will see the following in your function logs:
36+
```
37+
INFO [runtime] SIGTERM received
38+
INFO [runtime] Graceful shutdown in progress ...
39+
[runtime] Graceful shutdown completed
40+
```
+111
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,111 @@
1+
use lambda_extension::Extension;
2+
use lambda_runtime::{service_fn, tracing, Error, LambdaEvent};
3+
use serde::{Deserialize, Serialize};
4+
use tokio::signal::unix::{signal, SignalKind};
5+
6+
/// This is also a made-up example. Requests come into the runtime as unicode
7+
/// strings in json format, which can map to any structure that implements `serde::Deserialize`
8+
/// The runtime pays no attention to the contents of the request payload.
9+
#[derive(Deserialize)]
10+
struct Request {
11+
command: String,
12+
}
13+
14+
/// This is a made-up example of what a response structure may look like.
15+
/// There is no restriction on what it can be. The runtime requires responses
16+
/// to be serialized into json. The runtime pays no attention
17+
/// to the contents of the response payload.
18+
#[derive(Serialize)]
19+
struct Response {
20+
req_id: String,
21+
msg: String,
22+
}
23+
24+
pub(crate) async fn handler(event: LambdaEvent<Request>) -> Result<Response, Error> {
25+
// extract some useful info from the request
26+
let command = event.payload.command;
27+
28+
tracing::info!("executing {command:#}");
29+
30+
// prepare the response
31+
let resp = Response {
32+
req_id: event.context.request_id,
33+
msg: format!("Command {} executed.", command),
34+
};
35+
36+
// return `Response` (it will be serialized to JSON automatically by the runtime)
37+
Ok(resp)
38+
}
39+
40+
#[tokio::main]
41+
async fn main() -> Result<(), Error> {
42+
// Let's pretend this Lambda function is:
43+
// - sensitive to the tokio runtime being blocked due to heavy async concurrency in its handler
44+
// - stays fairly warm
45+
// - is somewhat long-running
46+
// In that case, we might prefer to avoid brief runtime blocks from flushing to stdout in the local context.
47+
// ref: https://github.com/tokio-rs/tracing/issues/2653
48+
//
49+
// So, we can use a dedicated logging thread with tracing_appender. The downside is that we need
50+
// to flush any outstanding entries before shutdown - hence the need for graceful shutdown.
51+
let (writer, log_guard) = tracing_appender::non_blocking(std::io::stdout());
52+
tracing::init_default_subscriber_with_writer(writer);
53+
54+
// You need an extension registered with the Lambda orchestrator in order for your process
55+
// to receive a SIGTERM for graceful shutdown.
56+
//
57+
// We accomplish this here by registering a no-op internal extension, which immediately returns.
58+
// (Unfortunately it does need to subscribe to at least one event type, in order to get a SIGTERM signal).
59+
// This adds overhead, but very little.
60+
//
61+
// You could also run a useful internal extension, such as in `../extension-internal-flush`.
62+
//
63+
// If an external extension (for example CloudWatch Lambda Insights) is running, it would register itself from outside
64+
// your Rust process and also get you SIGTERM. In that case, you don't need an internal extension at all.
65+
let extension = Extension::new()
66+
// Internal extensions only support INVOKE events.
67+
.with_events(&["INVOKE"])
68+
// Internal extension names MUST be unique within a given Lambda function.
69+
.with_extension_name("no-op")
70+
// Extensions MUST be registered before calling lambda_runtime::run(), which ends the Init
71+
// phase and begins the Invoke phase.
72+
.register()
73+
.await
74+
.expect("could not register extension");
75+
76+
// Handle SIGTERM signal.
77+
//
78+
// In this graceful shutdown, we flush our background logging thread by dropping its guard.
79+
//
80+
// More on signal handling:
81+
// https://tokio.rs/tokio/topics/shutdown
82+
// https://rust-cli.github.io/book/in-depth/signals.html
83+
tokio::spawn(async move {
84+
let mut sigint = signal(SignalKind::interrupt()).unwrap();
85+
let mut sigterm = signal(SignalKind::terminate()).unwrap();
86+
tokio::select! {
87+
_sigint = sigint.recv() => {
88+
tracing::info!("[runtime] SIGINT received");
89+
tracing::info!("[runtime] Graceful shutdown in progress ...");
90+
std::mem::drop(log_guard);
91+
92+
eprintln!("[runtime] Graceful shutdown completed");
93+
std::process::exit(0);
94+
},
95+
_sigterm = sigterm.recv()=> {
96+
tracing::info!("[runtime] SIGTERM received");
97+
tracing::info!("[runtime] Graceful shutdown in progress ...");
98+
std::mem::drop(log_guard);
99+
100+
eprintln!("[runtime] Graceful shutdown completed");
101+
std::process::exit(0);
102+
},
103+
}
104+
});
105+
106+
// TODO: add biased! to always poll the handler future first, once supported:
107+
// https://github.com/tokio-rs/tokio/issues/7304
108+
tokio::try_join!(lambda_runtime::run(service_fn(handler)), extension.run(),)?;
109+
110+
Ok(())
111+
}

lambda-runtime-api-client/src/tracing.rs

+34-3
Original file line numberDiff line numberDiff line change
@@ -14,12 +14,16 @@ pub use tracing::*;
1414

1515
/// Re-export the `tracing-subscriber` crate to build your own subscribers.
1616
pub use tracing_subscriber as subscriber;
17+
use tracing_subscriber::fmt::MakeWriter;
1718

1819
const DEFAULT_LOG_LEVEL: &str = "INFO";
1920

20-
/// Initialize `tracing-subscriber` with default logging options.
21+
/// Initialize `tracing-subscriber` with default logging options.
22+
///
23+
/// The default subscriber writes logs to STDOUT in the current context.
24+
/// If you want to customize the writer, see [`init_default_subscriber_with_writer()`].
2125
///
22-
/// This function uses environment variables set with [Lambda's advance logging controls](https://aws.amazon.com/blogs/compute/introducing-advanced-logging-controls-for-aws-lambda-functions/)
26+
/// This function uses environment variables set with [Lambda's advanced logging controls](https://aws.amazon.com/blogs/compute/introducing-advanced-logging-controls-for-aws-lambda-functions/)
2327
/// if they're configured for your function.
2428
///
2529
/// This subscriber sets the logging level based on environment variables:
@@ -31,6 +35,32 @@ const DEFAULT_LOG_LEVEL: &str = "INFO";
3135
/// If the `AWS_LAMBDA_LOG_FORMAT` environment variable is set to `JSON`, the log lines will be formatted as json objects,
3236
/// otherwise they will be formatted with the default tracing format.
3337
pub fn init_default_subscriber() {
38+
init_default_subscriber_with_writer(std::io::stdout);
39+
}
40+
41+
/// Initialize `tracing-subscriber` with default logging options, and a custom writer.
42+
///
43+
/// You might want to avoid writing to STDOUT in the local context via [`init_default_subscriber()`], if you have a high-throughput Lambdas that involve
44+
/// a lot of async concurrency. Since, writing to STDOUT can briefly block your tokio runtime - ref [tracing #2653](https://github.com/tokio-rs/tracing/issues/2653).
45+
/// In that case, you might prefer to use [tracing_appender::NonBlocking] instead - particularly if your Lambda is fairly long-running and stays warm.
46+
/// Though, note that you are then responsible
47+
/// for ensuring gracefuls shutdown. See [`examples/graceful-shutdown`] for a complete example.
48+
///
49+
/// This function uses environment variables set with [Lambda's advanced logging controls](https://aws.amazon.com/blogs/compute/introducing-advanced-logging-controls-for-aws-lambda-functions/)
50+
/// if they're configured for your function.
51+
///
52+
/// This subscriber sets the logging level based on environment variables:
53+
/// - if `AWS_LAMBDA_LOG_LEVEL` is set, it takes precedence over any other environment variables.
54+
/// - if `AWS_LAMBDA_LOG_LEVEL` is not set, check if `RUST_LOG` is set.
55+
/// - if none of those two variables are set, use `INFO` as the logging level.
56+
///
57+
/// The logging format can also be changed based on Lambda's advanced logging controls.
58+
/// If the `AWS_LAMBDA_LOG_FORMAT` environment variable is set to `JSON`, the log lines will be formatted as json objects,
59+
/// otherwise they will be formatted with the default tracing format.
60+
pub fn init_default_subscriber_with_writer<Writer>(writer: Writer)
61+
where
62+
Writer: for<'writer> MakeWriter<'writer> + Send + Sync + 'static,
63+
{
3464
let log_format = env::var("AWS_LAMBDA_LOG_FORMAT").unwrap_or_default();
3565
let log_level_str = env::var("AWS_LAMBDA_LOG_LEVEL").or_else(|_| env::var("RUST_LOG"));
3666
let log_level =
@@ -43,7 +73,8 @@ pub fn init_default_subscriber() {
4373
EnvFilter::builder()
4474
.with_default_directive(log_level.into())
4575
.from_env_lossy(),
46-
);
76+
)
77+
.with_writer(writer);
4778

4879
if log_format.eq_ignore_ascii_case("json") {
4980
collector.json().init()

0 commit comments

Comments
 (0)