aws-lambda-rust-runtime: Match error handling to other runtimes

The format of error messages returned by the runtime is hard to work with at the client end.

Example:

{
  "errorType": "alloc::boxed::Box<dyn std::error::Error+core::marker::Sync+core::marker::Send>",
  "errorMessage": "LambdaError { msg: \"cust error\", source: \"somewhere in code\", code: InvalidInput }"
}

It is produced by this code in https://github.com/awslabs/aws-lambda-rust-runtime/blob/f40461785625d8ac23e7c248367b1d724ef2b5ba/lambda/src/lib.rs#L216

Err(e) => EventErrorRequest {
                request_id,
                diagnostic: Diagnostic {
                    error_message: format!("{:?}", e),
                    error_type: type_name_of_val(e).to_owned(),
                },
            }
            .into_req()?,

with help from

fn type_name_of_val<T>(_: T) -> &'static str {
    std::any::type_name::<T>()
}

Proposed change

  1. Log the error message, probably via error! so that it appears in CloudWatch.
  2. Serialise e into JSON instead of Debug output ({:?}).
  3. Allow to set error type and fall back on std::any::type_name if none was provided.

Here are examples of what other runtimes are producing:

Discussion

I’m not 100% sure how it all can be implemented yet. Just wondering if this is a problem that impacts others and is worth looking into.

About this issue

  • Original URL
  • State: closed
  • Created 4 years ago
  • Reactions: 1
  • Comments: 35 (34 by maintainers)

Commits related to this issue

Most upvoted comments

Log the error message, probably via error! so that it appears in CloudWatch.

+1

I’m wondering if it helps to move things forward. can we separate how the error name is derived from how it is logged? there’s lots of ways to log an error but I assume there’s like one pretty good way to format the name of the error type.

On picking a log impl and size and all that. cargo feature flags can help with that!

I got it about .with_ansi(false). Can we tell tracing NOT to output the timestamp? It comes up twice in CloudWatch. That would be the only remaining difference with log.

Yup, here’s how: https://github.com/awslabs/aws-lambda-rust-runtime/blob/davidbarsky/update-readme/lambda/examples/hello-without-macro-tracing.rs#L16.

I presume that https://github.com/awslabs/aws-lambda-rust-runtime/blob/davidbarsky/update-readme/lambda/examples/hello-without-macro-log.rs#L10 enables tracing somehow.

Kinda. That’ll enable tracing’s log facade, which is in turn enabled by this feature. This feature was initially missing.

Also, when I tried to init the logger via simple_logger it had no effect on tracing - nothing was logged by the runtime.

Hrm, I’m unable to reproduce this. The first example below makes use of simple_logger and it has output from the lambda crate. tracing-subscriber output has a similar output, also from the lambda crate. Screen Shot 2020-07-22 at 10 53 36 PM


@brainstorm

I think using cargo bloat is a good idea, but I’d hold off on making a PR.

Just wanted to echo the voice of a minimal runtime again so something can ship soon. The problem to be solved here is to log an error, correct?

tracing feels a bit much just to print an error to the stdout/err. What was wrong with log::error!("{}", e) and letting the user select the log impl of their choice in their main again?

I’ll attempt a PR in a few days.

Further to the discussion on the bloat and the size of the binaries. Compiled with cargo build --release --target x86_64-unknown-linux-musl --examples. I have no idea if this is too big or OK. Just stating the facts.

Example Size
basic 6,771,664
error-handling 6,876,392
hello 6,703,288
hello-without-macro-log 6,793,136
hello-without-macro-tracing 6,960,136

@rimutaka

tracing adds complexity for no added benefit. Consider a case where some lambdas are in Node.JS and some are in Rust. Even if the handler outputs the same error message the output will look different with tracing. So now I have to make changes to my Appsync code, Vue, Graphana, and anything else that touches it to handle both variants.

This is where I disagree and regret mentioning tracing. tracing will not impact how your error will be rendered or logged; I only mentioned tracing in reference to your comment on https://github.com/rust-lang/log/issues/357 because it’ll allow you to preserve the fact that you’re recording an error if and only if you’re using a tracing Subscriber. log users will not benefit from this feature of tracing, but they will not be harmed either—they will merely get the fallback Debug or Display rendering.


With that being said—and please correct me if I’m wrong—this issue was opened to resolve how this runtime should report errors to the Invocation error endpoint. The current implementation has lots of room for improvement—I’ll accept ownership and blame for that.

I’ve personally found eyre::Report to be a really compelling illustration of the distinction between error handling and error reporting, the latter of which this issue focuses on. I’ll say this off the bat: I don’t think we can use eyre, but I think we can get some inspiration from its ideas. One approach I’ve been thinking about is keeping the Into<Box<dyn std::error::Error + Send + Sync + 'static>> bounds but (re)introducing a std::panic::set_hook-style error reporting hook to this runtime. It’ll have a closure that accepts a Box<dyn std::error::Error + Send + Sync + 'static>, but you’d be able to downcast to specific error variants and convert them to a Diagnostic accordingly. Here’s a limited example:

lambda::set_hook(Box::new(|e: Box<dyn std::error::Error + Send + Sync + 'static>| {
    if let Some(e) = e.downcast_ref::<std::io::Error>() {
        Diagnostic {
            error_message: format!("{}", e),
            error_type: "std::io::Error"
        } 
    }
    // handle any other variant you care to report, falling back to the `type_name`-based approach as a default.
    // I didn't write a fallback, but let's assume this closure _must_ return a `lambda::Diagnostic`.
}));

As @Veetaha mentioned in https://github.com/awslabs/aws-lambda-rust-runtime/issues/243#issuecomment-662741226, we’re between a rock (the current AWS APIs) and a hard place (the lack of stable specialization in Rust). This downcasting-based approach feels like the least bad approach to me, but what do you think?

Additionally, free to ping me directly over Discord or even setup a call. I’d be happy to walk through and discuss my thinking, which might be lossy over text.

Thanks for opening this issue! I’m personally inclined to use tracing over log(given that I’m one of the authors of tracing…), if only because it integrates with XRay already.

Allow to set error type and fall back on std::any::type_name if none was provided.

We had a similar set up in the past but required muuuch more machinery and was a bit onerous on the user end. There might still.be a way to have the best of both worlds with fancy downcasting. I’d propose some unit tests here. Might have caught the usability issue sooner

Serialise e into JSON instead of Debug output ({:?}).

I have an even simpler suggestion, use Display instead of Debug. Display is often implemented precisely for displaying a message. Debug is not meant for this purpose. You get this for free as implementing Error requires it so no extra type constraints are needed .