Merge rayon-rs#603

603: add demo to simulate usage in a game engine r=cuviper a=mdonoughe

It has been observed in amethyst/amethyst#780 that if you use Rayon in an environment where you are not CPU bound, you may end up using many more CPU cycles than necessary. This pull request adds an example of this problem to the demo project as a starting point towards finding a way to improve efficiency in this scenario.

The life demo now has a `play` mode where the same comparison of serial and parallel occurs, but with a frame (generation) per second limit in place and comparing CPU time measurements at the end.

Example output for my Ryzen 7 1800X with hyperthreading (16 logical processors) in Windows 10:

    $ rayon-demo life play
      serial: 59.93 fps
        cpu usage: 4.7%
    parallel: 59.97 fps
      cpu usage: 55.3%
    par_bridge: 59.94 fps
      cpu usage: 1164.1%

Once there are ways to improve the overhead they should be incorporated into this demo as an example. If there are already ways to improve the demo let me know and I can try to implement them now.

Co-authored-by: Matthew Donoughe <[email protected]>

Author: bors[bot]

rayon-demo/Cargo.toml

@@ -18,5 +18,11 @@ serde = "1"
 serde_derive = "1"
 time = "0.1"
 
+[target.'cfg(unix)'.dependencies]
+libc = "0.2"
+
+[target.'cfg(windows)'.dependencies]
+winapi = { version = "0.3", features = ["processthreadsapi"] }
+
 [dev-dependencies]
 num = "0.2"

rayon-demo/src/life/cpu_time/mod.rs

@@ -0,0 +1,20 @@
+use time::Duration;
+
+#[cfg(windows)]
+mod win;
+#[cfg(windows)]
+pub use self::win::get_cpu_time;
+
+#[cfg(unix)]
+mod unix;
+#[cfg(unix)]
+pub use self::unix::get_cpu_time;
+
+#[cfg(not(any(unix, windows)))]
+pub fn get_cpu_time() -> Option<u64> {
+    None
+}
+
+pub fn get_cpu_duration(start: Option<u64>, stop: Option<u64>) -> Option<Duration> {
+    start.and_then(|start| stop.and_then(|stop| Some(Duration::nanoseconds((stop - start) as i64))))
+}

rayon-demo/src/life/cpu_time/unix.rs

@@ -0,0 +1,14 @@
+use libc::{getrusage, rusage, RUSAGE_SELF};
+use std::mem;
+
+pub fn get_cpu_time() -> Option<u64> {
+    unsafe {
+        let mut usage: rusage = mem::uninitialized();
+        getrusage(RUSAGE_SELF, &mut usage);
+        let user = 1_000_000_000 * (usage.ru_utime.tv_sec as u64)
+            + 1_000 * (usage.ru_utime.tv_usec as u64);
+        let system = 1_000_000_000 * (usage.ru_stime.tv_sec as u64)
+            + 1_000 * (usage.ru_stime.tv_usec as u64);
+        Some(user + system)
+    }
+}

rayon-demo/src/life/cpu_time/win.rs

@@ -0,0 +1,17 @@
+use std::mem;
+use winapi::shared::minwindef::FILETIME;
+use winapi::um::processthreadsapi::{GetCurrentProcess, GetProcessTimes};
+
+pub fn get_cpu_time() -> Option<u64> {
+    unsafe {
+        let process = GetCurrentProcess();
+        let mut _creation: FILETIME = mem::uninitialized();
+        let mut _exit: FILETIME = mem::uninitialized();
+        let mut kernel: FILETIME = mem::uninitialized();
+        let mut user: FILETIME = mem::uninitialized();
+        GetProcessTimes(process, &mut _creation, &mut _exit, &mut kernel, &mut user);
+        let kernel = (kernel.dwHighDateTime as u64) << 32 | kernel.dwLowDateTime as u64;
+        let user = (user.dwHighDateTime as u64) << 32 | user.dwLowDateTime as u64;
+        Some(100 * (kernel + user))
+    }
+}

rayon-demo/src/life/mod.rs

@@ -1,13 +1,16 @@
 const USAGE: &'static str = "
 Usage: life bench [--size N] [--gens N]
+       life play [--size N] [--gens N] [--fps N]
        life --help
 Conway's Game of Life.
 
 Commands:
     bench           Run the benchmark in different modes and print the timings.
+    play            Run with a max frame rate and monitor CPU resources.
 Options:
     --size N        Size of the game board (N x N) [default: 200]
     --gens N        Simulate N generations [default: 100]
+    --fps N         Maximum frame rate [default: 60]
     -h, --help      Show this message.
 ";
 
@@ -17,6 +20,7 @@ use rand::distributions::Standard;
 use std::iter::repeat;
 use std::num::Wrapping;
 use std::sync::Arc;
+use std::thread;
 use time;
 
 use docopt::Docopt;
@@ -25,12 +29,15 @@ use rayon::iter::ParallelBridge;
 
 #[cfg(test)]
 mod bench;
+mod cpu_time;
 
 #[derive(Deserialize)]
 pub struct Args {
     cmd_bench: bool,
+    cmd_play: bool,
     flag_size: usize,
     flag_gens: usize,
+    flag_fps: usize,
 }
 
 #[derive(PartialEq, Eq, Clone, Debug)]
@@ -161,6 +168,44 @@ fn par_bridge_generations(board: Board, gens: usize) {
     for _ in 0..gens { brd = brd.par_bridge_next_generation(); }
 }
 
+fn delay(last_start: u64, min_interval_ns: u64) -> u64 {
+    let mut current_time = time::precise_time_ns();
+    let elapsed = current_time - last_start;
+    if elapsed < min_interval_ns {
+        let delay = min_interval_ns - elapsed;
+        thread::sleep(::std::time::Duration::from_nanos(delay));
+        current_time += delay;
+    }
+    current_time
+}
+
+fn generations_limited(board: Board, gens: usize, min_interval_ns: u64) {
+    let mut brd = board;
+    let mut time = time::precise_time_ns();
+    for _ in 0..gens {
+        brd = brd.next_generation();
+        time = delay(time, min_interval_ns);
+    }
+}
+
+fn parallel_generations_limited(board: Board, gens: usize, min_interval_ns: u64) {
+    let mut brd = board;
+    let mut time = time::precise_time_ns();
+    for _ in 0..gens {
+        brd = brd.parallel_next_generation();
+        time = delay(time, min_interval_ns);
+    }
+}
+
+fn par_bridge_generations_limited(board: Board, gens: usize, min_interval_ns: u64) {
+    let mut brd = board;
+    let mut time = time::precise_time_ns();
+    for _ in 0..gens {
+        brd = brd.par_bridge_next_generation();
+        time = delay(time, min_interval_ns);
+    }
+}
+
 fn measure(f: fn(Board, usize) -> (), args: &Args) -> u64 {
     let (n, gens) = (args.flag_size, args.flag_gens);
     let brd = Board::new(n, n).random();
@@ -171,6 +216,31 @@ fn measure(f: fn(Board, usize) -> (), args: &Args) -> u64 {
     time::precise_time_ns() - start
 }
 
+struct CpuResult {
+    actual_fps: f64,
+    cpu_usage_percent: Option<f64>,
+}
+
+fn measure_cpu(f: fn(Board, usize, u64) -> (), args: &Args) -> CpuResult {
+    let (n, gens, rate) = (args.flag_size, args.flag_gens, args.flag_fps);
+    let interval = 1_000_000_000 / rate as u64;
+    let brd = Board::new(n, n).random();
+    let start = time::precise_time_ns();
+    let cpu_start = cpu_time::get_cpu_time();
+
+    f(brd, gens, interval);
+
+    let cpu_stop = cpu_time::get_cpu_time();
+    let duration = time::precise_time_ns() - start;
+
+    CpuResult {
+        actual_fps: (1_000_000_000.0 * gens as f64) / duration as f64,
+        cpu_usage_percent: cpu_time::get_cpu_duration(cpu_start, cpu_stop)
+            .and_then(|cpu| cpu.num_nanoseconds())
+            .and_then(|cpu| Some(100.0 * cpu as f64 / duration as f64)),
+    }
+}
+
 pub fn main(args: &[String]) {
     let args: Args =
         Docopt::new(USAGE)
@@ -183,10 +253,30 @@ pub fn main(args: &[String]) {
 
         let parallel = measure(parallel_generations, &args);
         println!("parallel: {:10} ns -> {:.2}x speedup", parallel,
-                 serial as f64 / parallel as f64);
+            serial as f64 / parallel as f64);
 
         let par_bridge = measure(par_bridge_generations, &args);
         println!("par_bridge: {:10} ns -> {:.2}x speedup", par_bridge,
-                 serial as f64 / par_bridge as f64);
+            serial as f64 / par_bridge as f64);
+    }
+
+    if args.cmd_play {
+        let serial = measure_cpu(generations_limited, &args);
+        println!("  serial: {:.2} fps", serial.actual_fps);
+        if let Some(cpu_usage) = serial.cpu_usage_percent {
+            println!("    cpu usage: {:.1}%", cpu_usage);
+        }
+
+        let parallel = measure_cpu(parallel_generations_limited, &args);
+        println!("parallel: {:.2} fps", parallel.actual_fps);
+        if let Some(cpu_usage) = parallel.cpu_usage_percent {
+            println!("  cpu usage: {:.1}%", cpu_usage);
+        }
+
+        let par_bridge = measure_cpu(par_bridge_generations_limited, &args);
+        println!("par_bridge: {:.2} fps", par_bridge.actual_fps);
+        if let Some(cpu_usage) = par_bridge.cpu_usage_percent {
+            println!("  cpu usage: {:.1}%", cpu_usage);
+        }
     }
 }

rayon-demo/src/main.rs

@@ -33,6 +33,8 @@ extern crate serde; // all
 extern crate cgmath; // nbody
 #[macro_use]
 extern crate glium; // nbody
+#[cfg(unix)]
+extern crate libc; // life
 extern crate rand; // nbody
 extern crate time; // nbody, sieve
 extern crate odds; // sieve
@@ -42,6 +44,8 @@ extern crate num; // factorial
 extern crate lazy_static; // find
 extern crate fixedbitset; // tsp
 extern crate regex; // tsp
+#[cfg(windows)]
+extern crate winapi; // life
 
 #[cfg(test)]
 extern crate test;