Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

The restriction on the length of the content with a high RPS #286

Closed
soyayaos opened this issue May 4, 2017 · 21 comments
Closed

The restriction on the length of the content with a high RPS #286

soyayaos opened this issue May 4, 2017 · 21 comments
Labels
upstream An unresolvable issue: an upstream dependency bug

Comments

@soyayaos
Copy link

soyayaos commented May 4, 2017

Rocket version 0.2.6

Testing hello_world with wrk get the following results:

Content-Length = 8057B
test completed

Content-Length > 8057B
test completed with error
Failed to write response: Error { repr: Os { code: 32, message: "Broken pipe" } }.

wrk settings:

-t8 -c300 -d30s --latency --timeout 2s http://localhost:8000/

In any case, in manual mode (low RPS, browser), the server continues to give the page correctly.

@SergioBenitez
Copy link
Member

SergioBenitez commented May 9, 2017

Can you be specific about how you're manipulating the hello_world example, if at all? How are you modifying the Content-Length? I'm not able to replicate this with the hello_world example in the repository.

How are you running Rocket? To benchmark the hello_world example, you should run it as:

ROCKET_ENV=prod ROCKET_PORT=8000 cargo run --release

@soyayaos
Copy link
Author

soyayaos commented May 9, 2017

Terminal 1: build default example

$ uname -a
Linux ub1604 4.8.0-49-generic #52~16.04.1-Ubuntu SMP Thu Apr 20 10:55:59 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
$ cat /etc/issue
Ubuntu 16.04.2 LTS \n \l
$ cd /tmp
$ git clone https://github.com/SergioBenitez/Rocket/
$ cd Rocket/examples/hello_world/
$ cargo build --release
$ sudo ROCKET_ENV=production ../../target/release/hello_world

Terminal 2: test default example

$ curl -I -s http://localhost:80/ | grep Content-Length
Content-Length: 13
$ wrk -t8 -c300 -d30s --latency --timeout 2s http://localhost:80/
Running 30s test @ http://localhost:80/
  8 threads and 300 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   173.83us   87.15us  24.03ms   97.29%
    Req/Sec    21.33k    10.30k   34.24k    44.00%
  Latency Distribution
     50%  165.00us
     75%  192.00us
     90%  219.00us
     99%  339.00us
  1273076 requests in 30.08s, 177.26MB read
Requests/sec:  42324.26
Transfer/sec:      5.89MB

RPS 42324 :)

Terminal 1: change "Hello, world!" to "aaa..." (8057 bytes)

^C
$ STR=`head -c 8057 < /dev/zero | tr '\0' '\141'`;sed -i -e "s/Hello, world\!/$STR/g" src/main.rs
$ cat src/main.rs 
#![feature(plugin)]
#![plugin(rocket_codegen)]

extern crate rocket;

#[cfg(test)] mod tests;

#[get("/")]
fn hello() -> &'static str {
    "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
}

fn main() {
    rocket::ignite().mount("/", routes![hello]).launch();
}
$ cargo build --release
$ sudo ROCKET_ENV=production ../../target/release/hello_world

Terminal 2: test 8057 bytes

$ curl -I -s http://localhost:80/ | grep Content-Length
Content-Length: 8057
$ wrk -t8 -c300 -d30s --latency --timeout 2s http://localhost:80/
Running 30s test @ http://localhost:80/
  8 threads and 300 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   189.81us  107.63us  19.59ms   96.99%
    Req/Sec    19.69k     4.79k   28.50k    54.91%
  Latency Distribution
     50%  176.00us
     75%  208.00us
     90%  243.00us
     99%  404.00us
  1177641 requests in 30.10s, 8.98GB read
Requests/sec:  39128.84
Transfer/sec:    305.69MB

RPS 39128 :)

Terminal 1: change 8057 bytes string to 8058 bytes string

^C
$ STROLD=`head -c 8057 < /dev/zero | tr '\0' '\141'`;STRNEW=`head -c 8058 < /dev/zero | tr '\0' '\141'`;sed -i -e "s/$STROLD/$STRNEW/g" src/main.rs 
$ cargo build --release
$ sudo ROCKET_ENV=production ../../target/release/hello_world

Terminal 2: test 8058 bytes string

$ curl -I -s http://localhost:80/ | grep Content-Length
Content-Length: 8058
$ wrk -t8 -c300 -d30s --latency --timeout 2s http://localhost:80/
Running 30s test @ http://localhost:80/
  8 threads and 300 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    44.01ms    1.78ms  48.15ms   96.59%
    Req/Sec    90.97     48.40   181.00     62.50%
  Latency Distribution
     50%   43.96ms
     75%   44.01ms
     90%   44.06ms
     99%   47.99ms
  5448 requests in 30.07s, 42.57MB read
Requests/sec:    181.15
Transfer/sec:      1.42MB

RPS 181 :(

Terminal 1: errors

🚀  Rocket has launched from http://0.0.0.0:80
Error: No matching routes for HEAD /.
Error: Failed to write response: Error { repr: Os { code: 32, message: "Broken pipe" } }.
Error: Failed to write response: Error { repr: Os { code: 32, message: "Broken pipe" } }.
Error: Failed to write response: Error { repr: Os { code: 32, message: "Broken pipe" } }.
...

@SergioBenitez
Copy link
Member

SergioBenitez commented May 9, 2017

There are some changes in master related to connection handling. Can you try the same test on master and see if the issue is fixed? I'm not able to reproduce this.

@soyayaos
Copy link
Author

soyayaos commented May 11, 2017

I tried to test with 1 thread and 11 connections (num_cpu + 3)

wrk -t1 -c11 -d5s --latency --timeout 2s http://127.0.0.1:8000

and with

panic!();

here.

Panic example:

stack backtrace:
   0: std::sys::imp::backtrace::tracing::imp::unwind_backtrace
             at /checkout/src/libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
   1: std::sys_common::backtrace::_print
             at /checkout/src/libstd/sys_common/backtrace.rs:71
   2: std::panicking::default_hook::{{closure}}
             at /checkout/src/libstd/sys_common/backtrace.rs:60
             at /checkout/src/libstd/panicking.rs:355
   3: std::panicking::default_hook
             at /checkout/src/libstd/panicking.rs:371
   4: std::panicking::rust_panic_with_hook
             at /checkout/src/libstd/panicking.rs:549
   5: std::panicking::begin_panic
             at /checkout/src/libstd/panicking.rs:511
   6: rocket::rocket::Rocket::issue_response
             at /tmp/Rocket/lib/src/rocket.rs:117
   7: <rocket::rocket::Rocket as hyper::server::Handler>::handle
             at /tmp/Rocket/lib/src/rocket.rs:77
   8: <hyper::server::Worker<H>>::keep_alive_loop
             at /home/vovagp/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.10.10/src/server/mod.rs:346
   9: <hyper::server::Worker<H>>::handle_connection
             at /home/vovagp/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.10.10/src/server/mod.rs:292
  10: hyper::server::handle::{{closure}}
             at /home/vovagp/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.10.10/src/server/mod.rs:251
  11: hyper::server::listener::spawn_with::{{closure}}
             at /home/vovagp/.cargo/registry/src/github.com-1ecc6299db9ec823/hyper-0.10.10/src/server/listener.rs:50
  12: <std::panic::AssertUnwindSafe<F> as core::ops::FnOnce<()>>::call_once
             at /checkout/src/libstd/panic.rs:296
  13: std::panicking::try::do_call
             at /checkout/src/libstd/panicking.rs:454
  14: __rust_maybe_catch_panic
             at /checkout/src/libpanic_unwind/lib.rs:98
  15: std::panicking::try
             at /checkout/src/libstd/panicking.rs:433
  16: std::panic::catch_unwind
             at /checkout/src/libstd/panic.rs:361
  17: std::thread::Builder::spawn::{{closure}}
             at /checkout/src/libstd/thread/mod.rs:368
  18: <F as alloc::boxed::FnBox<A>>::call_box
             at /checkout/src/liballoc/boxed.rs:648
  19: std::sys::imp::thread::Thread::new::thread_start
             at /checkout/src/liballoc/boxed.rs:658
             at /checkout/src/libstd/sys_common/thread.rs:21
             at /checkout/src/libstd/sys/unix/thread.rs:84
  20: start_thread
  21: clone

Please, see full log here. Last 3 connections is broken.

In any case, hyper hello_world with same (or greater) Content-Length works correctly.

@SergioBenitez
Copy link
Member

@vovagp Can you try with the latest Rocket code, the one in master? This should be as simple as:

git clone https://github.com/SergioBenitez/Rocket.git
cd Rocket/examples/hello_world
ROCKET_ENV=prod ROCKET_PORT=8000 cargo run --release

Then run your wrk commands and see if you have the same issue.

@soyayaos
Copy link
Author

@SergioBenitez yes, this is last version of Rocket.

@soyayaos
Copy link
Author

Same errors in Debian 8 (Virtualbox):

root@debian:/tmp# uname -a
Linux debian 3.16.0-4-amd64 #1 SMP Debian 3.16.39-1+deb8u2 (2017-03-07) x86_64 GNU/Linux
root@debian:/tmp# cat /etc/issue
Debian GNU/Linux 8 \n \l

What OS are you using?

@SergioBenitez
Copy link
Member

@vovagp Your logs indicate that you're not using the code from master, from the git repository. Are you sure you're using the version in master? Also, if possible, can you hop on Rocket's IRC/Matrix channel to discuss this in real-time?

@soyayaos
Copy link
Author

@SergioBenitez This logs from

RUST_BACKTRACE=1 ROCKET_LOG="debug" cargo run --verbose

command. I had to get the backtrace of the error.

Ok, I will go to IRC.

@SergioBenitez SergioBenitez added the bug Deviation from the specification or expected behavior label May 11, 2017
@SergioBenitez
Copy link
Member

Okay, I was able to reproduce this on Debian. Taking a look at what's causing the issue now.

@soyayaos
Copy link
Author

@SergioBenitez Ok, i on #rocket channel now.

@SergioBenitez
Copy link
Member

Thus far, there is no obvious or semi-obvious issue with Rocket.

I started tweaking the parameters of wrk and rocket to try to localize the issue. Here are my current findings:

  • The issue only occurs when the response is >= 8058 bytes.
  • The issue occurs when flushing the response write.
  • Rocket only emits an error on the last write. IE, when wrk closes its last socket.
  • The issue occurs even with ROCKET_WORKERS=1.
  • The issue does not occur when wrk -c < 2.
  • Requests/seconds drops from ~100k to 200 when crossing from 8057 to 8058.

The last bullet point is the most surprising; why would RPS drop so dramatically when crossing the 8048 boundary? One clue is that Rocket uses io::copy, which uses a an 8KiB buffer, which is 8192, but that still leaves 144 bytes unaccounted for. Even then, this doesn't seem liable to cause the issue.

So, I considered whether wrk might be the culprit here. Thus, I tried with ab. Indeed, ab works flawlessly (note that ab isn't nearly as fast as wrk):

$ ab -n 20000 -c 16 -k http://127.0.0.1:8000/
This is ApacheBench, Version 2.3 <$Revision: 1757674 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking 127.0.0.1 (be patient)
Completed 2000 requests
Completed 4000 requests
Completed 6000 requests
Completed 8000 requests
Completed 10000 requests
Completed 12000 requests
Completed 14000 requests
Completed 16000 requests
Completed 18000 requests
Completed 20000 requests
Finished 20000 requests


Server Software:        Rocket
Server Hostname:        127.0.0.1
Server Port:            8000

Document Path:          /
Document Length:        8058 bytes

Concurrency Level:      16
Time taken for tests:   1.107 seconds
Complete requests:      20000
Failed requests:        0
Keep-Alive requests:    0
Total transferred:      163860000 bytes
HTML transferred:       161160000 bytes
Requests per second:    18073.82 [#/sec] (mean)
Time per request:       0.885 [ms] (mean)
Time per request:       0.055 [ms] (mean, across all concurrent requests)
Transfer rate:          144608.20 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.1      0       1
Processing:     0    1   0.1      1       3
Waiting:        0    0   0.0      0       2
Total:          0    1   0.1      1       3

Percentage of the requests served within a certain time (ms)
  50%      1
  66%      1
  75%      1
  80%      1
  90%      1
  95%      1
  98%      1
  99%      1
 100%      3 (longest request)

This means that either wrk is sending HTTP requests in some way that triggers a bug in Rocket/Hyper, or that there's a bug in wrk itself. Working on doing some more debugging to figure this out.

@SergioBenitez SergioBenitez added the upstream An unresolvable issue: an upstream dependency bug label May 11, 2017
@SergioBenitez
Copy link
Member

Update: I was able to replicate this with standalone Hyper (cc @seanmonstar) with this code. As such, if there is an issue, it lies in Hyper. At the moment, given the evidence, I'm inclined to believe that something's going on with wrk and Hyper is okay.

@SergioBenitez SergioBenitez removed the bug Deviation from the specification or expected behavior label May 11, 2017
@soyayaos
Copy link
Author

soyayaos commented May 11, 2017

In Ubuntu 16.04 this code works without errors.

Without env_logger: Requests/sec: 94611.31
With env_logger: Requests/sec: 69774.61

curl -I http://127.0.0.1:3000/
HTTP/1.1 200 OK
Content-Type: text/plain; charset=utf-8
Server: hyper*
Content-Length: 8057
Date: Thu, 11 May 2017 21:02:31 GMT

hyper = "0.10.10"
env_logger = "0.4.2"

$ rustc --version
rustc 1.19.0-nightly (d3abc80b3 2017-05-09)

@SergioBenitez
Copy link
Member

@vovagp Whoops! Sorry, was missing an 'a' there (I removed one to confirm that the issue was indeed occurring). I've updated the gist.

@soyayaos
Copy link
Author

@SergioBenitez It seems the problem in headers or headers + content length:

curl -I -s http://127.0.0.1:3000/ | grep Server
Server: 11111

Requests/sec: 110385.55

Added 1 byte

curl -I -s http://127.0.0.1:3000/ | grep Server
Server: 111111

Requests/sec:    228.51

@soyayaos
Copy link
Author

OK, problem seems in 8192 bytes buffer.

curl --head http://127.0.0.1:3000/
HTTP/1.1 200 OK
Content-Length: 8115
Date: Thu, 11 May 2017 21:45:09 GMT

8115 + 78 (headers size) = 8193

And wrk resut:

Requests/sec:    226.73

For

curl --head http://127.0.0.1:3000/
HTTP/1.1 200 OK
Content-Length: 8114
Date: Thu, 11 May 2017 21:48:14 GM

result is

Requests/sec: 127066.00

@SergioBenitez
Copy link
Member

@vovagp Because the issue occurs with just plain Hyper, it's not the call to io::copy that Rocket is making that is causing this problem. At this point, I'm inclined to believe that the issue is with wrk. I'd be curious to see if the issue occurs with other benchmarking tools as well. I've confirmed that it does not occur with ab: perhaps other tools can serve as evidence?

@soyayaos
Copy link
Author

@SergioBenitez yes, problem with Hyper. I don't think that the problem may be with wrk. We check the backend, not client. For example, Nginx (with Lua or only static) or Netty or Cowboy works fine with wrk. Im sure, it's serverside problem.

@soyayaos
Copy link
Author

I created new issue hyperium/hyper#1184

@SergioBenitez
Copy link
Member

Looks like this was an issue with Nagle's in Hyper, which still exists but won't be dealt with. We'll deal with this in #17.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
upstream An unresolvable issue: an upstream dependency bug
Projects
None yet
Development

No branches or pull requests

2 participants