Skip to content

Commit 8f96b37

Browse files
committed
timing changes
1 parent ce33c33 commit 8f96b37

File tree

3 files changed

+115
-8
lines changed

3 files changed

+115
-8
lines changed

src/librustc/Cargo.toml

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -59,4 +59,6 @@ chalk-engine = { version = "0.6.0", default-features=false }
5959
flate2 = "1.0"
6060
tempdir = "0.3"
6161

62-
62+
[target.'cfg(windows)'.dependencies]
63+
kernel32-sys = "0.2.2"
64+
winapi = "0.2.8"

src/librustc/lib.rs

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -40,6 +40,7 @@
4040
html_favicon_url = "https://doc.rust-lang.org/favicon.ico",
4141
html_root_url = "https://doc.rust-lang.org/nightly/")]
4242

43+
#![feature(asm)]
4344
#![feature(box_patterns)]
4445
#![feature(box_syntax)]
4546
#![feature(const_fn)]
@@ -86,6 +87,10 @@ extern crate graphviz;
8687
#[cfg(windows)]
8788
extern crate libc;
8889
extern crate polonius_engine;
90+
#[cfg(windows)]
91+
extern crate kernel32;
92+
#[cfg(windows)]
93+
extern crate winapi;
8994
extern crate rustc_target;
9095
#[macro_use] extern crate rustc_data_structures;
9196
extern crate serialize;

src/librustc/util/common.rs

Lines changed: 107 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -176,6 +176,20 @@ pub fn time_ext<T, F>(do_it: bool, sess: Option<&Session>, what: &str, f: F) ->
176176
profq_msg(sess, ProfileQueriesMsg::TimeBegin(what.to_string()))
177177
}
178178
}
179+
180+
#[cfg(not(all(windows, parallel_queries, any(target_arch = "x86", target_arch = "x86_64"))))]
181+
let rv = time_impl(sess, what, f);
182+
#[cfg(all(windows, parallel_queries, any(target_arch = "x86", target_arch = "x86_64")))]
183+
let rv = time_threads_impl(sess, what, f);
184+
185+
TIME_DEPTH.with(|slot| slot.set(old));
186+
187+
rv
188+
}
189+
190+
fn time_impl<T, F>(sess: Option<&Session>, what: &str, f: F) -> T where
191+
F: FnOnce() -> T,
192+
{
179193
let start = Instant::now();
180194
let rv = f();
181195
let dur = start.elapsed();
@@ -184,12 +198,98 @@ pub fn time_ext<T, F>(do_it: bool, sess: Option<&Session>, what: &str, f: F) ->
184198
profq_msg(sess, ProfileQueriesMsg::TimeEnd)
185199
}
186200
}
201+
print_time_passes_entry_internal(what, duration_to_secs_str(dur));
202+
rv
203+
}
187204

188-
print_time_passes_entry_internal(what, dur);
205+
#[cfg(all(windows, parallel_queries, any(target_arch = "x86", target_arch = "x86_64")))]
206+
fn time_threads_impl<T, F>(sess: Option<&Session>, what: &str, f: F) -> T where
207+
F: FnOnce() -> T,
208+
{
209+
use rayon_core::registry;
210+
use std::iter;
211+
use winapi;
212+
use kernel32;
189213

190-
TIME_DEPTH.with(|slot| slot.set(old));
214+
#[allow(unused_mut)]
215+
fn read_counter() -> u64 {
216+
let mut low: u32;
217+
let mut high: u32;
191218

192-
rv
219+
unsafe {
220+
asm!("xor %rax, %rax; cpuid; rdtsc"
221+
: "={eax}" (low), "={edx}" (high) :: "memory", "rbx", "rcx");
222+
}
223+
224+
((high as u64) << 32) | (low as u64)
225+
}
226+
227+
let registry = registry::get_current_registry();
228+
if let Some(registry) = registry {
229+
let freq = unsafe {
230+
let mut freq = 0;
231+
assert!(kernel32::QueryPerformanceFrequency(&mut freq) == winapi::TRUE);
232+
freq as u64 * 1000
233+
};
234+
235+
let threads: Vec<_> = {
236+
let threads = registry.handles.lock();
237+
let current = unsafe {
238+
iter::once(kernel32::GetCurrentThread())
239+
};
240+
current.chain(threads.iter().map(|t| t.0)).collect()
241+
};
242+
let mut begin: Vec<u64> = iter::repeat(0).take(threads.len()).collect();
243+
let mut end: Vec<u64> = iter::repeat(0).take(threads.len()).collect();
244+
for (i, &handle) in threads.iter().enumerate() {
245+
unsafe {
246+
assert!(kernel32::QueryThreadCycleTime(handle, &mut begin[i]) == winapi::TRUE);
247+
}
248+
}
249+
250+
let time_start = read_counter();
251+
let result = f();
252+
let time_end = read_counter();
253+
for (i, &handle) in threads.iter().enumerate() {
254+
unsafe {
255+
assert!(kernel32::QueryThreadCycleTime(handle, &mut end[i]) == winapi::TRUE);
256+
}
257+
}
258+
if let Some(sess) = sess {
259+
if cfg!(debug_assertions) {
260+
profq_msg(sess, ProfileQueriesMsg::TimeEnd)
261+
}
262+
}
263+
let time = time_end - time_start;
264+
let time_secs = time as f64 / freq as f64;
265+
266+
let thread_times: Vec<u64> = end.iter().zip(begin.iter()).map(|(e, b)| *e - *b).collect();
267+
268+
let total_thread_time: u64 = thread_times.iter().cloned().sum();
269+
let core_usage = total_thread_time as f64 / time as f64;
270+
271+
let mut data = format!("{:.6} - cores {:.2}x - cpu {:.2} - threads (",
272+
time_secs,
273+
core_usage,
274+
core_usage / (thread_times.len() - 1) as f64);
275+
276+
for (i, thread_time) in thread_times.into_iter().enumerate() {
277+
data.push_str(&format!("{:.2}", thread_time as f64 / time as f64));
278+
if i == 0 {
279+
data.push_str(" - ");
280+
}
281+
else if i < begin.len() - 1 {
282+
data.push_str(" ");
283+
}
284+
}
285+
286+
data.push_str(")");
287+
288+
print_time_passes_entry_internal(what, data);
289+
result
290+
} else {
291+
time_impl(sess, what, f)
292+
}
193293
}
194294

195295
pub fn print_time_passes_entry(do_it: bool, what: &str, dur: Duration) {
@@ -203,12 +303,12 @@ pub fn print_time_passes_entry(do_it: bool, what: &str, dur: Duration) {
203303
r
204304
});
205305

206-
print_time_passes_entry_internal(what, dur);
306+
print_time_passes_entry_internal(what, duration_to_secs_str(dur));
207307

208308
TIME_DEPTH.with(|slot| slot.set(old));
209309
}
210310

211-
fn print_time_passes_entry_internal(what: &str, dur: Duration) {
311+
fn print_time_passes_entry_internal(what: &str, data: String) {
212312
let indentation = TIME_DEPTH.with(|slot| slot.get());
213313

214314
let mem_string = match get_resident() {
@@ -220,7 +320,7 @@ fn print_time_passes_entry_internal(what: &str, dur: Duration) {
220320
};
221321
println!("{}time: {}{}\t{}",
222322
repeat(" ").take(indentation).collect::<String>(),
223-
duration_to_secs_str(dur),
323+
data,
224324
mem_string,
225325
what);
226326
}
@@ -232,7 +332,7 @@ pub fn duration_to_secs_str(dur: Duration) -> String {
232332
let secs = dur.as_secs() as f64 +
233333
dur.subsec_nanos() as f64 / NANOS_PER_SEC;
234334

235-
format!("{:.3}", secs)
335+
format!("{:.6}", secs)
236336
}
237337

238338
pub fn to_readable_str(mut val: usize) -> String {

0 commit comments

Comments
 (0)