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

Implement initializer() for FileDesc #53981

Merged
merged 1 commit into from
Sep 8, 2018
Merged

Conversation

fbernier
Copy link
Contributor

@fbernier fbernier commented Sep 6, 2018

Here was my initial issue:

use std::process::{Command};

fn main() {
    let output = Command::new("curl").arg("-s").arg("http://ovh.net/files/100Mio.dat").output();
    println!("{:?}", output.unwrap().stdout.len());
}
~/stuff ❯❯❯ time ./dwl
104857600
./dwl  16.22s user 1.80s system 23% cpu 1:15.24 total
use std::process::{Command, Stdio};

fn main() {
    let child = Command::new("curl").arg("-s").arg("http://ovh.net/files/100Mio.dat").stdout(Stdio::piped()).spawn();
    let output = child.unwrap().wait_with_output().unwrap();
    println!("{:?}", output.stdout.len());
}
~/stuff ❯❯❯ time ./dwl2
104857600
./dwl2  0.64s user 2.18s system 5% cpu 53.072 total

As you can see the first version is spending much more time in userland and also uses more cpu. I discovered that the slow version uses two pipes, one for stdin and one for stderr and in that case it polls when going through this function. The polling calls read_to_end on the pipes repetitively and this results in zeroing its internal buffer each time. To avoid this zeroing, FileDesc needs to implement initializer. I see no reason why it wouldn't work with uninitialized memory so this PR fixes that.

Here is some tracing of the slow program:
image

versus the fast program:
image

I have not tested the change yet but will try to build it tomorrow.

@rust-highfive
Copy link
Collaborator

Thanks for the pull request, and welcome! The Rust team is excited to review your changes, and you should hear from @shepmaster (or someone else) soon.

If any changes to this PR are deemed necessary, please add them as extra commits. This ensures that the reviewer can see what has changed since they last reviewed the code. Due to the way GitHub handles out-of-date commits, this should also make it reasonably obvious what issues have or haven't been addressed. Large or tricky changes may require several passes of review and changes.

Please see the contribution instructions for more information.

@rust-highfive rust-highfive added the S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. label Sep 6, 2018
@rust-highfive
Copy link
Collaborator

The job x86_64-gnu-llvm-5.0 of your PR failed on Travis (raw log). Through arcane magic we have determined that the following fragments from the build log may contain information about the problem.

Click to expand the log.

[00:04:39] travis_fold:start:tidy
travis_time:start:tidy
tidy check
[00:04:40] tidy error: /checkout/src/libstd/sys/unix/fd.rs:273: trailing whitespace
[00:04:41] some tidy checks failed
[00:04:41] 
[00:04:41] 
[00:04:41] command did not execute successfully: "/checkout/obj/build/x86_64-unknown-linux-gnu/stage0-tools-bin/tidy" "/checkout/src" "/checkout/obj/build/x86_64-unknown-linux-gnu/stage0/bin/cargo" "--no-vendor" "--quiet"
[00:04:41] 
[00:04:41] 
[00:04:41] failed to run: /checkout/obj/build/bootstrap/debug/bootstrap test src/tools/tidy
[00:04:41] Build completed unsuccessfully in 0:00:50
[00:04:41] Build completed unsuccessfully in 0:00:50
[00:04:41] Makefile:79: recipe for target 'tidy' failed
[00:04:41] make: *** [tidy] Error 1

The command "stamp sh -x -c "$RUN_SCRIPT"" exited with 2.
travis_time:start:000711fe
$ date && (curl -fs --head https://google.com | grep ^Date: | sed 's/Date: //g' || true)
---
travis_time:end:1745749e:start=1536204014148158746,finish=1536204014154855559,duration=6696813
travis_fold:end:after_failure.3
travis_fold:start:after_failure.4
travis_time:start:2f08ca58
$ ln -s . checkout && for CORE in obj/cores/core.*; do EXE=$(echo $CORE | sed 's|obj/cores/core\.[0-9]*\.!checkout!\(.*\)|\1|;y|!|/|'); if [ -f "$EXE" ]; then printf travis_fold":start:crashlog\n\033[31;1m%s\033[0m\n" "$CORE"; gdb -q -c "$CORE" "$EXE" -iex 'set auto-load off' -iex 'dir src/' -iex 'set sysroot .' -ex bt -ex q; echo travis_fold":"end:crashlog; fi; done || true
travis_fold:end:after_failure.4
travis_fold:start:after_failure.5
travis_time:start:1d860a70
travis_time:start:1d860a70
$ cat ./obj/build/x86_64-unknown-linux-gnu/native/asan/build/lib/asan/clang_rt.asan-dynamic-i386.vers || true
cat: ./obj/build/x86_64-unknown-linux-gnu/native/asan/build/lib/asan/clang_rt.asan-dynamic-i386.vers: No such file or directory
travis_fold:end:after_failure.5
travis_fold:start:after_failure.6
travis_time:start:004e24cc
$ dmesg | grep -i kill

I'm a bot! I can only do what humans tell me to, so if this was not helpful or you have suggestions for improvements, please ping or otherwise contact @TimNN. (Feature Requests)

@rust-highfive
Copy link
Collaborator

The job x86_64-gnu-llvm-5.0 of your PR failed on Travis (raw log). Through arcane magic we have determined that the following fragments from the build log may contain information about the problem.

Click to expand the log.
[00:05:36] 
[00:05:36] error[E0412]: cannot find type `Initializer` in this scope
[00:05:36]    --> libstd/sys/unix/fd.rs:275:37
[00:05:36]     |
[00:05:36] 275 |     unsafe fn initializer(&self) -> Initializer {
[00:05:36] help: possible candidate is found in another module, you can import it into scope
[00:05:36]     |
[00:05:36] 13  | use io::Initializer;
[00:05:36]     |
---
[00:05:38] For more information about an error, try `rustc --explain E0412`.
[00:05:38] error: Could not compile `std`.
[00:05:38] 
[00:05:38] Caused by:
[00:05:38]   process didn't exit successfully: `/checkout/obj/build/bootstrap/debug/rustc --crate-name std libstd/lib.rs --color always --error-format json --crate-type dylib --crate-type rlib --emit=dep-info,link -C prefer-dynamic -C opt-level=2 --cfg 'feature="alloc_jemalloc"' --cfg 'feature="backtrace"' --cfg 'feature="jemalloc"' --cfg 'feature="panic-unwind"' --cfg 'feature="panic_unwind"' -C metadata=c29a53bc81e5db39 -C extra-filename=-c29a53bc81e5db39 --out-dir /checkout/obj/build/x86_64-unknown-linux-gnu/stage0-std/x86_64-unknown-linux-gnu/release/deps --target x86_64-unknown-linux-gnu -L dependency=/checkout/obj/build/x86_64-unknown-linux-gnu/stage0-std/x86_64-unknown-linux-gnu/release/deps -L dependency=/checkout/obj/build/x86_64-unknown-linux-gnu/stage0-std/release/deps --extern alloc=/checkout/obj/build/x86_64-unknown-linux-gnu/stage0-std/x86_64-unknown-linux-gnu/release/deps/liballoc-eb136989b0a4d15b.rlib --extern alloc_jemalloc=/checkout/obj/build/x86_64-unknown-linux-gnu/stage0-std/x86_64-unknown-linux-gnu/release/deps/liballoc_jemalloc-3dc5fad39cb0df5f.rlib --extern alloc_system=/checkout/obj/build/x86_64-unknown-linux-gnu/stage0-std/x86_64-unknown-linux-gnu/release/deps/liballoc_system-21bc9e10c694662b.rlib --extern compiler_builtins=/checkout/obj/build/x86_64-unknowKtravis_fold:end:after_failure.5
travis_time:start:16ee12d0
$ dmesg | grep -i kill
[   10.868734] init: failsafe main process (1092) killed by TERM signal
travis_time:end:16ee12d0:start=1536205020589319801,finish=1536205020601053446,duration=11733645

I'm a bot! I can only do what humans tell me to, so if this was not helpful or you have suggestions for improvements, please ping or otherwise contact @TimNN. (Feature Requests)

in order to avoid constantly zeroing memory when it's not needed.
@fbernier
Copy link
Contributor Author

fbernier commented Sep 6, 2018

r? @sfackler from the git history I think this could be interesting to you.

@rust-highfive rust-highfive assigned sfackler and unassigned shepmaster Sep 6, 2018
@sfackler
Copy link
Member

sfackler commented Sep 7, 2018

@bors r+

Thanks!

@bors
Copy link
Contributor

bors commented Sep 7, 2018

📌 Commit 28745a6 has been approved by sfackler

@bors bors added S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion. and removed S-waiting-on-review Status: Awaiting review from the assignee but also interested parties. labels Sep 7, 2018
kennytm added a commit to kennytm/rust that referenced this pull request Sep 8, 2018
Implement initializer() for FileDesc

Here was my initial issue:

```rust
use std::process::{Command};

fn main() {
    let output = Command::new("curl").arg("-s").arg("http://ovh.net/files/100Mio.dat").output();
    println!("{:?}", output.unwrap().stdout.len());
}
```
```
~/stuff ❯❯❯ time ./dwl
104857600
./dwl  16.22s user 1.80s system 23% cpu 1:15.24 total
```

```rust
use std::process::{Command, Stdio};

fn main() {
    let child = Command::new("curl").arg("-s").arg("http://ovh.net/files/100Mio.dat").stdout(Stdio::piped()).spawn();
    let output = child.unwrap().wait_with_output().unwrap();
    println!("{:?}", output.stdout.len());
}
```

```
~/stuff ❯❯❯ time ./dwl2
104857600
./dwl2  0.64s user 2.18s system 5% cpu 53.072 total
```

As you can see the first version is spending much more time in userland and also uses more cpu. With the help of @programble, @talchas and @habnabit  on the rust IRC, we discovered that the slow version uses two pipes, one for `stdin` and one for `stderr` and in that case it polls when going through [this function](https://github.com/rust-lang/rust/blob/master/src/libstd/sys/unix/pipe.rs#L82). The polling calls `read_to_end` on the pipes repetitively and this results in zeroing its internal buffer each time. To avoid this zeroing, `FileDesc` needs to implement `initializer`. We see no reason why it [wouldn't work with uninitialized memory](https://doc.rust-lang.org/1.26.1/src/std/io/mod.rs.html#534) so this PR fixes that.

Here is some tracing of the slow program:
![image](https://user-images.githubusercontent.com/147585/45133180-ed8a2d80-b161-11e8-9ec7-09979ec96145.png)

versus the fast program:
![image](https://user-images.githubusercontent.com/147585/45133216-0c88bf80-b162-11e8-908e-ff81d59239fb.png)

I have not tested the change yet but will try to build it tomorrow.
bors added a commit that referenced this pull request Sep 8, 2018
Rollup of 11 pull requests

Successful merges:

 - #51366 (stabilize #[panic_handler])
 - #53162 (rustdoc: collect trait impls as an early pass)
 - #53932 ([NLL] Remove base_place)
 - #53942 (Rewrite `precompute_borrows_out_of_scope` for fewer hash table lookups.)
 - #53973 (Have rust-lldb look for the rust-enabled lldb)
 - #53981 (Implement initializer() for FileDesc)
 - #53987 (rustbuild: allow configuring llvm version suffix)
 - #53993 (rustc_resolve: don't record uniform_paths canaries as reexports.)
 - #54007 (crates that provide a `panic_handler` are exempt from the `unused_extern_crates` lint)
 - #54040 (update books for next release)
 - #54050 (Update `petgraph` dependency to 0.4.13 to fix build with nightly)

Failed merges:

r? @ghost
kennytm added a commit to kennytm/rust that referenced this pull request Sep 8, 2018
Implement initializer() for FileDesc

Here was my initial issue:

```rust
use std::process::{Command};

fn main() {
    let output = Command::new("curl").arg("-s").arg("http://ovh.net/files/100Mio.dat").output();
    println!("{:?}", output.unwrap().stdout.len());
}
```
```
~/stuff ❯❯❯ time ./dwl
104857600
./dwl  16.22s user 1.80s system 23% cpu 1:15.24 total
```

```rust
use std::process::{Command, Stdio};

fn main() {
    let child = Command::new("curl").arg("-s").arg("http://ovh.net/files/100Mio.dat").stdout(Stdio::piped()).spawn();
    let output = child.unwrap().wait_with_output().unwrap();
    println!("{:?}", output.stdout.len());
}
```

```
~/stuff ❯❯❯ time ./dwl2
104857600
./dwl2  0.64s user 2.18s system 5% cpu 53.072 total
```

As you can see the first version is spending much more time in userland and also uses more cpu. With the help of @programble, @talchas and @habnabit  on the rust IRC, we discovered that the slow version uses two pipes, one for `stdin` and one for `stderr` and in that case it polls when going through [this function](https://github.com/rust-lang/rust/blob/master/src/libstd/sys/unix/pipe.rs#L82). The polling calls `read_to_end` on the pipes repetitively and this results in zeroing its internal buffer each time. To avoid this zeroing, `FileDesc` needs to implement `initializer`. We see no reason why it [wouldn't work with uninitialized memory](https://doc.rust-lang.org/1.26.1/src/std/io/mod.rs.html#534) so this PR fixes that.

Here is some tracing of the slow program:
![image](https://user-images.githubusercontent.com/147585/45133180-ed8a2d80-b161-11e8-9ec7-09979ec96145.png)

versus the fast program:
![image](https://user-images.githubusercontent.com/147585/45133216-0c88bf80-b162-11e8-908e-ff81d59239fb.png)

I have not tested the change yet but will try to build it tomorrow.
bors added a commit that referenced this pull request Sep 8, 2018
Rollup of 10 pull requests

Successful merges:

 - #53315 (use `NonZeroU32` in `newtype_index!`macro, change syntax)
 - #53932 ([NLL] Remove base_place)
 - #53942 (Rewrite `precompute_borrows_out_of_scope` for fewer hash table lookups.)
 - #53973 (Have rust-lldb look for the rust-enabled lldb)
 - #53981 (Implement initializer() for FileDesc)
 - #53987 (rustbuild: allow configuring llvm version suffix)
 - #53993 (rustc_resolve: don't record uniform_paths canaries as reexports.)
 - #54007 (crates that provide a `panic_handler` are exempt from the `unused_extern_crates` lint)
 - #54040 (update books for next release)
 - #54050 (Update `petgraph` dependency to 0.4.13 to fix build with nightly)
@bors bors merged commit 28745a6 into rust-lang:master Sep 8, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
S-waiting-on-bors Status: Waiting on bors to run and complete tests. Bors will change the label on completion.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

5 participants