In alomost every request, lambda runtime is logging an "ERROR" despite returning correctly

[Bryson14]

I've noticed in cloud watch, there is an Error that is logged from the lambda runtime which is consistently happening every request.

Here is the code that has a trace on the axum web server:

#![warn(clippy::cargo, clippy::unwrap_used)]
mod config;
mod dynamodb_actions;
mod models;
mod route_handlers;
mod web_server;
use aws_sdk_dynamodb::Client;
use config::{make_config, Opt};
use lambda_runtime::tower::ServiceBuilder;
use std::env::set_var;
use tower_http::add_extension::AddExtensionLayer;
use web_server::get_router;

pub fn get_router() -> axum::Router {
    // Sets the axum router to produce only ERROR level logs. The handlers can produce their own level of logs.
    const LOG_LEVEL: Level = Level::ERROR;

    // With Routing, order does matter, so put the more specific first and then more generic routes later
    let mut app = Router::new()
        // more routes here
        .route("/*path", get(catch_get).post(catch_post))
        .layer(
            TraceLayer::new_for_http()
                .make_span_with(trace::DefaultMakeSpan::new().level(LOG_LEVEL))
                .on_response(trace::DefaultOnResponse::new().level(LOG_LEVEL)),
        );

#[tokio::main]
async fn main() -> Result<(), lambda_http::Error> {
    // AWS Runtime can ignore Stage Name passed from json event
    // https://github.com/awslabs/aws-lambda-rust-runtime/issues/782
    set_var("AWS_LAMBDA_HTTP_IGNORE_STAGE_IN_PATH", "true");

    // required to enable CloudWatch error logging by the runtime
    tracing_subscriber::fmt()
        .with_max_level(tracing::Level::INFO)
        // disable printing the name of the module in every log line.
        .with_target(false)
        // disabling time is handy because CloudWatch will add the ingestion time.
        .without_time()
        .init();

    // creating a dynamo db client for the router to use
    let config = make_config(Opt {
        region: None,
        verbose: true,
    })
    .await;
    let client = std::sync::Arc::new(Client::new(
        &config.expect("Could not unwrap aws config for dynamodb client"),
    ));

    let router = get_router();
    // TODO how to work with stages inside the routing?

    // adding the client into the router as an extension layer
    let router = ServiceBuilder::new()
        .layer(AddExtensionLayer::new(client))
        .service(router);

    lambda_http::run(router).await
}

The ERROR log will look like this for every request:

ERROR Lambda runtime invoke{requestId="0b184a12-cf1e-42ea-9e30-8883b6d98bad" xrayTraceId="Root=1-65c3a6f6-6a5a0dd91e2b154a75fbbbca;Parent=9379824870f73984;Sampled=1;Lineage=22c583ee:0"}:request{method=POST uri=https://rigt30tiul.execute-api.us-east-1.amazonaws.com/message version=HTTP/1.1}: finished processing request latency=5 ms status=201 | ERROR Lambda runtime invoke{requestId="0b184a12-cf1e-42ea-9e30-8883b6d98bad" xrayTraceId="Root=1-65c3a6f6-6a5a0dd91e2b154a75fbbbca;Parent=9379824870f73984;Sampled=1;Lineage=22c583ee:0"}:request{method=POST uri=https://rigt30tiul.execute-api.us-east-1.amazonaws.com/message version=HTTP/1.1}: finished processing request latency=5 ms status=201

I'm not sure why it happens. To get rid of this warning, I removed the layer(TraceLayer::new_for_http()) from the router and now it has gone away.

[calavera]

The message comes with the " Lambda runtime invoke" description because it's inside the execution span. https://github.com/awslabs/aws-lambda-rust-runtime/blob/94b33e864e94a1dde1462a9ad4bc72d4213a00b1/lambda-runtime/src/types.rs#L163

You'll have to look into the TraceLayer documentation to understand why it prints the span as an error. This is not caused by the runtime as you point out.

[github-actions[bot]]

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.