handle_error increases compiles a lot

[davidpdrsn]

It seems adding handle_error to a router will increase compile times quite significantly.

Here is an example:

use axum::{service::ServiceExt, prelude::*, http::StatusCode};
use std::convert::Infallible;
use std::net::SocketAddr;
use std::time::Duration;
use tower::{BoxError, ServiceBuilder};
use tower_http::trace::TraceLayer;

#[tokio::main]
async fn main() {
    let app = route("/", get(handler))
        .nest(
            "/api",
            route("/pay/get_pay_params", post(handler))
                .nest(
                    "/user",
                    route("/create", post(handler))
                        .route("/login", post(handler))
                        .route("/info", get(handler))
                        .route("/update_password", get(handler)),
                )
                .nest(
                    "/product",
                    route("/list", get(handler)).route("/detail", get(handler)),
                ),
        )
        .layer(
            ServiceBuilder::new()
                .timeout(Duration::from_secs(10))
                .layer(TraceLayer::new_for_http())
                .into_inner(),
        )
        .handle_error(|error: BoxError| {
            if error.is::<tower::timeout::error::Elapsed>() {
                Ok::<_, Infallible>((
                    StatusCode::REQUEST_TIMEOUT,
                    "request took too long".to_string(),
                ))
            } else {
                Ok::<_, Infallible>((
                    StatusCode::INTERNAL_SERVER_ERROR,
                    format!("Unhandled internal error: {}", error),
                ))
            }
        });

    let addr: SocketAddr = "127.0.0.1".parse::<SocketAddr>().unwrap();
    axum::Server::bind(&addr)
        .serve(app.into_make_service())
        .await
        .unwrap();
}

async fn handler() -> &'static str {
    "index"
}

With the handle_error it compiles in 5s and in 0.3s without, on my machine in debug mode. Whether this is a rustc issue or something we can improve directly via axum I don't know. Something to investigate for sure.

[jplatte]

On my machine the difference is even worse. Around 10s for cargo check with handle_error, around 0.5s without it (this is with 1.54). Now trying with nightly and then some debug options...

edit(1): Same with rustc 1.56.0-nightly (a6ece5615 2021-08-03)

[jplatte]

Ran with RUSTFLAGS='-Ztime-passes', these are the clearly deviating entries:

# w/o handle_error
time:   0.265; rss:  139MB ->  219MB (  +79MB)	item_bodies_checking
time:   0.268; rss:  121MB ->  219MB (  +97MB)	type_check_crate
time:   0.334; rss:   45MB ->  102MB (  +57MB)	total

# w/ handle_error
time:   9.814; rss:  133MB ->  747MB ( +615MB)	item_bodies_checking
time:   9.815; rss:  129MB ->  747MB ( +618MB)	type_check_crate
time:   9.919; rss:   45MB ->  105MB (  +60MB)	total

[lnicola]

Yeah, in self-profile the time goes into analysis and typeck. I'd file a rustc issue, but I suspect it's a known problem.

[ZhangHanDong]

On my machine (macos m1), using handle_error took 10s (1/3) longer than without handle_error.

[ZhangHanDong]

Use this to print a compile time report ： cargo +nightly build -Z timings .

[lnicola]

That's not going to help. self-profile should, but it doesn't seem to.

Usage:

• RUSTFLAGS="-Zself-profile -Zself-profile-events=default,args" cargo check
• cargo clean -p feiyuan-web
• RUSTFLAGS="-Zself-profile -Zself-profile-events=default,args" cargo +nightly check
• crox feiyuan_web-33490.mm_profdata
• open Chrome and load the resulting profile.json in the performance inspector

[davidpdrsn]

I just filed rust-lang/rust#87924

[davidpdrsn]

I've managed to find a work around that doesn't impact compile times:

use axum::body::{box_body, BoxBody};
use axum::prelude::*;
use futures::future::{FutureExt, Map};
use http::Response;
use std::task::{Context, Poll};
use std::{net::SocketAddr, time::Duration};
use tower::Service;
use tower::{BoxError, ServiceBuilder};
use tower_http::trace::TraceLayer;

#[tokio::main]
async fn main() {
    // Set the RUST_LOG, if it hasn't been explicitly defined
    if std::env::var("RUST_LOG").is_err() {
        std::env::set_var("RUST_LOG", "hello_world=debug")
    }
    tracing_subscriber::fmt::init();

    let app = route("/", get(handler))
        .nest(
            "/api",
            route("/pay/get_pay_params", post(handler))
                .nest(
                    "/user",
                    route("/create", post(handler))
                        .route("/login", post(handler))
                        .route("/info", get(handler))
                        .route("/update_password", get(handler)),
                )
                .nest(
                    "/product",
                    route("/list", get(handler)).route("/detail", get(handler)),
                ),
        )
        .layer(
            ServiceBuilder::new()
                .timeout(Duration::from_secs(10))
                .layer(TraceLayer::new_for_http())
                .into_inner(),
        );

    let app = app.layer(tower::layer::layer_fn(HandleError::new));

    // run it
    let addr = SocketAddr::from(([127, 0, 0, 1], 3000));
    tracing::debug!("listening on {}", addr);
    axum::Server::bind(&addr)
        .serve(app.into_make_service())
        .await
        .unwrap();
}

async fn handler() -> response::Html<&'static str> {
    response::Html("<h1>Hello, World!</h1>")
}

#[derive(Debug, Clone)]
pub struct HandleError<S> {
    inner: S,
}

impl<S> HandleError<S> {
    pub fn new(inner: S) -> Self {
        Self { inner }
    }
}

impl<S, R, B> Service<R> for HandleError<S>
where
    S: Service<R, Response = Response<B>>,
    S::Error: Into<BoxError>,
    B: axum::body::HttpBody<Data = axum::body::Bytes> + Send + Sync + 'static,
    B::Error: Into<BoxError>,
{
    type Response = Response<BoxBody>;
    type Error = S::Error;
    #[allow(clippy::type_complexity)]
    type Future =
        Map<S::Future, fn(Result<S::Response, Self::Error>) -> Result<Self::Response, Self::Error>>;

    fn poll_ready(&mut self, cx: &mut Context<'_>) -> Poll<Result<(), Self::Error>> {
        self.inner.poll_ready(cx)
    }

    fn call(&mut self, req: R) -> Self::Future {
        self.inner.call(req).map(|result| match result {
            Ok(res) => Ok(res.map(box_body)),
            Err(err) => Ok(handle_error(err.into())),
        })
    }
}

fn handle_error(error: BoxError) -> Response<BoxBody> {
    todo!("your code here")
}

The only downside is that it doesn't change the error type of the service to Infallible but no errors will be produced in practice.

[davidpdrsn]

I just merged #184 which should help compile times a bit. Let me know if someone tries it!

[vaniusrb]

I got a very small improvement. Before your change, my project cargo check took ~60 seconds. With your commit takes 44.83s.
Add a .boxed() after last .route() still being the best workaround, where takes 9.09s.

If I add more routes rustc stays running until reaches OOM.

(I cloned axum git repo to my disk and changed in the cargo.toml to read it, to discard any cargo cache)

[davidpdrsn]

@vaniusrb Can you share a reproduction?

[vaniusrb]

@davidpdrsn Here: https://github.com/vaniusrb/axum-slow-compile
Note: this is basically the "todo" example with more routes.

[davidpdrsn]

Thanks! If you use #198 and remove the check_infallible call it compiles in under 1 second for me. So #198 seems to be working!

Just have to look into check_infallible. Could probably just remove it 🤷 Not sure its very useful as you can check the return type of handle_error.

[davidpdrsn]

I was able to find a fix for check_infallible b70e8cc. The example @vaniusrb posted now compiles in less than 1 sec on my machine. Thanks for posting it!

Even with 100 routes (without boxing) cargo check takes 1.5 seconds 🎊

[vaniusrb]

@davidpdrsn Confirmed! Thank you very much. You are awesome.

[davidpdrsn]

If someone still has compile time issues when using main please post here.