rtiow: cleanup elapsed time logging.

This commit is contained in:
Bill Thiede 2023-02-12 14:09:11 -08:00
parent ac555beafc
commit 88b8c547e0
2 changed files with 15 additions and 12 deletions

View File

@ -8,7 +8,7 @@ use std::{
Arc, Mutex, Arc, Mutex,
}, },
thread, thread,
time::{self, Instant}, time::{Duration, Instant},
}; };
use core_affinity; use core_affinity;
@ -363,13 +363,13 @@ fn progress(
start_time: Instant, start_time: Instant,
last_stat: &RenderStats, last_stat: &RenderStats,
current_stat: &RenderStats, current_stat: &RenderStats,
time_diff: time::Duration, time_diff: Duration,
pixel_total: usize, pixel_total: usize,
) -> String { ) -> String {
let human = human::Formatter::new(); let human = human::Formatter::new();
let pixel_diff = current_stat.pixels - last_stat.pixels; let pixel_diff = current_stat.pixels - last_stat.pixels;
let ray_diff = current_stat.rays - last_stat.rays; let ray_diff = current_stat.rays - last_stat.rays;
let now = time::Instant::now(); let now = Instant::now();
let start_diff = now - start_time; let start_diff = now - start_time;
let ratio = current_stat.pixels as f32 / pixel_total as f32; let ratio = current_stat.pixels as f32 / pixel_total as f32;
let percent = ratio * 100.; let percent = ratio * 100.;
@ -577,10 +577,10 @@ pub fn render(scene: Scene, output_dir: &Path) -> std::result::Result<(), std::i
info!("Rendering with {} subsamples", scene.subsamples); info!("Rendering with {} subsamples", scene.subsamples);
let pixel_total = scene.width * scene.height; let pixel_total = scene.width * scene.height;
let mut last_time = time::Instant::now(); let mut last_time = Instant::now();
let mut last_stat: RenderStats = Default::default(); let mut last_stat: RenderStats = Default::default();
let mut current_stat: RenderStats = Default::default(); let mut current_stat: RenderStats = Default::default();
let start_time = time::Instant::now(); let render_start_time = Instant::now();
for resp in pixel_resp_rx { for resp in pixel_resp_rx {
match resp { match resp {
Response::Pixel { x, y, pixel, rs } => { Response::Pixel { x, y, pixel, rs } => {
@ -595,13 +595,13 @@ pub fn render(scene: Scene, output_dir: &Path) -> std::result::Result<(), std::i
} }
} }
let now = time::Instant::now(); let now = Instant::now();
let time_diff = now - last_time; let time_diff = now - last_time;
if time_diff > time::Duration::from_secs(5) { if time_diff > Duration::from_secs(5) {
println!( println!(
"{}", "{}",
progress( progress(
start_time, render_start_time,
&last_stat, &last_stat,
&current_stat, &current_stat,
time_diff, time_diff,
@ -615,12 +615,12 @@ pub fn render(scene: Scene, output_dir: &Path) -> std::result::Result<(), std::i
for thr in handles { for thr in handles {
thr.join().expect("thread join"); thr.join().expect("thread join");
} }
let time_diff = time::Instant::now() - start_time; let time_diff = Instant::now() - render_start_time;
println!( println!(
"Runtime {} seconds {}", "Render {} seconds {}",
time_diff.as_secs_f32(), time_diff.as_secs_f32(),
progress( progress(
start_time, render_start_time,
&Default::default(), &Default::default(),
&current_stat, &current_stat,
time_diff, time_diff,

View File

@ -1,5 +1,5 @@
#![warn(unused_extern_crates)] #![warn(unused_extern_crates)]
use std::fs; use std::{fs, time::Instant};
#[cfg(feature = "profile")] #[cfg(feature = "profile")]
use cpuprofiler::PROFILER; use cpuprofiler::PROFILER;
@ -36,6 +36,7 @@ impl MockProfiler {
static PROFILER: MockProfiler = MockProfiler {}; static PROFILER: MockProfiler = MockProfiler {};
fn main() -> Result<(), std::io::Error> { fn main() -> Result<(), std::io::Error> {
let start_time = Instant::now();
stderrlog::new() stderrlog::new()
.verbosity(3) .verbosity(3)
.timestamp(stderrlog::Timestamp::Millisecond) .timestamp(stderrlog::Timestamp::Millisecond)
@ -65,5 +66,7 @@ fn main() -> Result<(), std::io::Error> {
PROFILER.lock().unwrap().stop().unwrap(); PROFILER.lock().unwrap().stop().unwrap();
} }
let time_diff = Instant::now() - start_time;
info!("Total runtime {} seconds", time_diff.as_secs_f32());
res res
} }