search

actix / actix-web

Actix Web is a powerful, pragmatic, and extremely fast web framework for Rust.
https://actix.rs
Apache License 2.0
21.6k stars 1.67k forks source link

Middleware Logging is too slow #852

Closed nnao45 closed 5 years ago

nnao45 commented 5 years ago

Hi. I use actix, and I write code is too slow when using logging middleware Should I fix this?

platform

OS: Debian 4.9.130-2 (2018-10-27) x86_64 GNU/Linux Platform: GCP, GCE Machine Type: n1-standard-4(vCPU: 4, Memory, 15G) Rust Version: cargo 1.36.0-nightly (759b6161a 2019-05-06)

nouse middleware

extern crate env_logger;

use std::sync::Arc;
use std::sync::atomic::{AtomicUsize, Ordering};
use std::{thread, time};

use actix::prelude::*;
use actix_web::{error, server, App, AsyncResponder, FutureResponse, HttpRequest, HttpResponse};
use actix_web::http::Method;
use actix_web::middleware::{ Middleware, Started, Response };
use actix_web::middleware::Logger;
use futures::Future;
use futures::future;
use std::time::SystemTime;

struct ApplicationState {
    counter     : AtomicUsize
}

pub struct Server;
impl Server {

    fn health(_: &HttpRequest<Arc<ApplicationState>>) -> &'static str { "ok" }

    pub fn start(&self) {
        std::env::set_var("RUST_LOG", "actix_web=info");
        env_logger::init();
        let state = Arc::new(ApplicationState {
                counter     : AtomicUsize::new(0)
            });

        server::HttpServer::new(move || {
            vec![
                App::with_state(state.clone())
                    //.middleware(Logger::default())
                    //.middleware(Logger::new("%a %{User-Agent}i"))
                    .resource("/hc",          |r| r.method(Method::GET).f(Server::health))
            ]
        })
            .bind("127.0.0.1:8787")
            .unwrap()
            .workers(8)
            .run()
    }
}
siege -c 100 -r 1000 --benchmarkrk http://127.0.0.1:8787/hc
[alert] Zip encoding disabled; siege requires zlib support to enable it
** SIEGE 4.0.2
** Preparing 100 concurrent users for battle.
The server is now under siege...
Transactions:                 100000 hits
Availability:                 100.00 %
Elapsed time:                   7.55 secs
Data transferred:               0.19 MB
Response time:                  0.01 secs
Transaction rate:           13245.03 trans/sec
Throughput:                     0.03 MB/sec
Concurrency:                   96.11
Successful transactions:      100000
Failed transactions:               0
Longest transaction:            0.24
Shortest transaction:           0.00

use middleware

extern crate env_logger;

use std::sync::Arc;
use std::sync::atomic::{AtomicUsize, Ordering};
use std::{thread, time};

use actix::prelude::*;
use actix_web::{error, server, App, AsyncResponder, FutureResponse, HttpRequest, HttpResponse};
use actix_web::http::Method;
use actix_web::middleware::{ Middleware, Started, Response };
use actix_web::middleware::Logger;
use futures::Future;
use futures::future;
use std::time::SystemTime;

struct ApplicationState {
    counter     : AtomicUsize
}

pub struct Server;
impl Server {

    fn health(_: &HttpRequest<Arc<ApplicationState>>) -> &'static str { "ok" }

    pub fn start(&self) {
        std::env::set_var("RUST_LOG", "actix_web=info");
        env_logger::init();
        let state = Arc::new(ApplicationState {
                counter     : AtomicUsize::new(0)
            });

        server::HttpServer::new(move || {
            vec![
                App::with_state(state.clone())
                    .middleware(Logger::default())
                    .middleware(Logger::new("%a %{User-Agent}i"))
                    .resource("/hc",          |r| r.method(Method::GET).f(Server::health))
            ]
        })
            .bind("127.0.0.1:8787")
            .unwrap()
            .workers(8)
            .run()
    }
}
siege -c 100 -r 1000 --benchmark http://127.0.0.1:8787/hc
[alert] Zip encoding disabled; siege requires zlib support to enable it
** SIEGE 4.0.2
** Preparing 100 concurrent users for battle.
The server is now under siege...
Transactions:                 100000 hits
Availability:                 100.00 %
Elapsed time:                 153.23 secs
Data transferred:               0.19 MB
Response time:                  0.15 secs
Transaction rate:             652.61 trans/sec
Throughput:                     0.00 MB/sec
Concurrency:                   98.38
Successful transactions:      100000
Failed transactions:               0
Longest transaction:            3.53
Shortest transaction:           0.00
fafhrd91 commented 5 years ago

sure, you can try. Could you test 1.0-rc version? 0.7 is in maintenance mode

nnao45 commented 5 years ago

@fafhrd91 thank you for reply.

Could you test 1.0-rc version?

Okay, Done. But...I look like slow... do you think?

platform

OS: Debian 4.9.130-2 (2018-10-27) x86_64 GNU/Linux
Platform: GCP, GCE
Machine Type: n1-standard-4(vCPU: 4, Memory, 15G)
Rust Version: cargo 1.36.0-nightly (759b6161a 2019-05-06)

Cargo.toml

[package]
name = "basics"
version = "1.0.0"
authors = ["nnao45 <n4sekai5y@gmail.com>"]
workspace = ".."
edition = "2018"

[dependencies]
actix-rt = "0.2"
actix-web = "1.0.0-rc"

futures = "0.1.25"
env_logger = "0.5"
bytes = "0.4"

Code

#[macro_use]
extern crate actix_web;

use std::{env, io};

use actix_web::http::{header, Method, StatusCode};
use actix_web::{
    error, guard, middleware, web, App, Error, HttpRequest, HttpResponse, HttpServer,
    Result,
};
use bytes::Bytes;
use futures::unsync::mpsc;
use futures::{future::ok, Future, Stream};

#[get("/hc")]
fn hc() ->  Result<HttpResponse> {
   Ok(HttpResponse::build(StatusCode::OK)
        .content_type("plain/text; charset=utf-8")
        .body(Bytes::from(&b"OK"[..])))
}

fn main() -> io::Result<()> {
    env::set_var("RUST_LOG", "actix_web=debug");
    env_logger::init();
    let sys = actix_rt::System::new("basic-example");

    HttpServer::new(|| {
        App::new()
            // enable logger
            .wrap(middleware::Logger::default())
            .service(hc)
    })
    .bind("10.146.0.5:8787")?
    .start();

    sys.run()
}

Test report

siege -c 100 -r 1000 --benchmark http://10.146.0.5:8787/hc
[alert] Zip encoding disabled; siege requires zlib support to enable it
** SIEGE 4.0.2
** Preparing 100 concurrent users for battle.
The server is now under siege...
Transactions:                 100000 hits
Availability:                 100.00 %
Elapsed time:                  88.43 secs
Data transferred:               0.19 MB
Response time:                  0.09 secs
Transaction rate:            1130.84 trans/sec
Throughput:                     0.00 MB/sec
Concurrency:                   97.15
Successful transactions:      100000
Failed transactions:               0
Longest transaction:            0.98
Shortest transaction:           0.00
fafhrd91 commented 5 years ago

expected numbers for console logging