Skip to content

Commit b385d51

Browse files
committed
Auto merge of #7381 - alexcrichton:cpu-usage-graph, r=ehuss
Update `-Ztimings` with CPU usage information This commit updates the graph generated by `-Ztimings` to include CPU usage information, ideally showing how Cargo/rustc used the CPU throughout the build, ideally seeing nice periods of parallelism and also periods of missed parallelism.
2 parents d96c050 + 1d5d19e commit b385d51

File tree

5 files changed

+303
-4
lines changed

5 files changed

+303
-4
lines changed

src/cargo/core/compiler/job_queue.rs

Lines changed: 14 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@ use std::marker;
55
use std::mem;
66
use std::sync::mpsc::{channel, Receiver, Sender};
77
use std::sync::Arc;
8+
use std::time::Duration;
89

910
use crossbeam_utils::thread::Scope;
1011
use failure::format_err;
@@ -321,15 +322,26 @@ impl<'a, 'cfg> JobQueue<'a, 'cfg> {
321322
// to the jobserver itself.
322323
tokens.truncate(self.active.len() - 1);
323324

325+
// Record some timing information if `-Ztimings` is enabled, and
326+
// this'll end up being a noop if we're not recording this
327+
// information.
324328
self.timings
325329
.mark_concurrency(self.active.len(), queue.len(), self.queue.len());
330+
self.timings.record_cpu();
326331

327332
// Drain all events at once to avoid displaying the progress bar
328-
// unnecessarily.
333+
// unnecessarily. If there's no events we actually block waiting for
334+
// an event, but we keep a "heartbeat" going to allow `record_cpu`
335+
// to run above to calculate CPU usage over time. To do this we
336+
// listen for a message with a timeout, and on timeout we run the
337+
// previous parts of the loop again.
329338
let events: Vec<_> = self.rx.try_iter().collect();
330339
let events = if events.is_empty() {
331340
self.show_progress(finished, total);
332-
vec![self.rx.recv().unwrap()]
341+
match self.rx.recv_timeout(Duration::from_millis(500)) {
342+
Ok(message) => vec![message],
343+
Err(_) => continue,
344+
}
333345
} else {
334346
events
335347
};

src/cargo/core/compiler/timings.js

Lines changed: 24 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -193,6 +193,21 @@ function render_timing_graph() {
193193
y: TOP_MARGIN + GRAPH_HEIGHT * (1.0 - (v / max_v))
194194
};
195195
}
196+
197+
const cpuFillStyle = 'rgba(250, 119, 0, 0.2)';
198+
ctx.beginPath();
199+
ctx.fillStyle = cpuFillStyle;
200+
let bottomLeft = coord(CPU_USAGE[0][0], 0);
201+
ctx.moveTo(bottomLeft.x, bottomLeft.y);
202+
for (let i=0; i < CPU_USAGE.length; i++) {
203+
let [time, usage] = CPU_USAGE[i];
204+
let {x, y} = coord(time, usage / 100.0 * max_v);
205+
ctx.lineTo(x, y);
206+
}
207+
let bottomRight = coord(CPU_USAGE[CPU_USAGE.length - 1][0], 0);
208+
ctx.lineTo(bottomRight.x, bottomRight.y);
209+
ctx.fill();
210+
196211
function draw_line(style, key) {
197212
let first = CONCURRENCY_DATA[0];
198213
let last = coord(first.t, key(first));
@@ -216,15 +231,15 @@ function render_timing_graph() {
216231
// Draw a legend.
217232
ctx.restore();
218233
ctx.save();
219-
ctx.translate(graph_width-120, MARGIN);
234+
ctx.translate(graph_width-150, MARGIN);
220235
// background
221236
ctx.fillStyle = '#fff';
222237
ctx.strokeStyle = '#000';
223238
ctx.lineWidth = 1;
224239
ctx.textBaseline = 'middle'
225240
ctx.textAlign = 'start';
226241
ctx.beginPath();
227-
ctx.rect(0, 0, 120, 62);
242+
ctx.rect(0, 0, 150, 82);
228243
ctx.stroke();
229244
ctx.fill();
230245

@@ -251,6 +266,13 @@ function render_timing_graph() {
251266
ctx.stroke();
252267
ctx.fillText('Active', 54, 51);
253268

269+
ctx.beginPath();
270+
ctx.fillStyle = cpuFillStyle
271+
ctx.fillRect(15, 60, 30, 15);
272+
ctx.fill();
273+
ctx.fillStyle = 'black';
274+
ctx.fillText('CPU Usage', 54, 71);
275+
254276
ctx.restore();
255277
}
256278

src/cargo/core/compiler/timings.rs

Lines changed: 41 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@
55
use super::{CompileMode, Unit};
66
use crate::core::compiler::BuildContext;
77
use crate::core::PackageId;
8+
use crate::util::cpu::State;
89
use crate::util::machine_message::{self, Message};
910
use crate::util::{paths, CargoResult, Config};
1011
use std::collections::HashMap;
@@ -46,6 +47,13 @@ pub struct Timings<'a, 'cfg> {
4647
/// Concurrency-tracking information. This is periodically updated while
4748
/// compilation progresses.
4849
concurrency: Vec<Concurrency>,
50+
/// Last recorded state of the system's CPUs and when it happened
51+
last_cpu_state: Option<State>,
52+
last_cpu_recording: Instant,
53+
/// Recorded CPU states, stored as tuples. First element is when the
54+
/// recording was taken and second element is percentage usage of the
55+
/// system.
56+
cpu_usage: Vec<(f64, f64)>,
4957
}
5058

5159
/// Tracking information for an individual unit.
@@ -134,6 +142,9 @@ impl<'a, 'cfg> Timings<'a, 'cfg> {
134142
unit_times: Vec::new(),
135143
active: HashMap::new(),
136144
concurrency: Vec::new(),
145+
last_cpu_state: State::current().ok(),
146+
last_cpu_recording: Instant::now(),
147+
cpu_usage: Vec::new(),
137148
}
138149
}
139150

@@ -253,6 +264,31 @@ impl<'a, 'cfg> Timings<'a, 'cfg> {
253264
self.total_dirty += 1;
254265
}
255266

267+
/// Take a sample of CPU usage
268+
pub fn record_cpu(&mut self) {
269+
if !self.enabled {
270+
return;
271+
}
272+
let prev = match &mut self.last_cpu_state {
273+
Some(state) => state,
274+
None => return,
275+
};
276+
// Don't take samples too too frequently, even if requested.
277+
let now = Instant::now();
278+
if self.last_cpu_recording.elapsed() < Duration::from_millis(100) {
279+
return;
280+
}
281+
let current = match State::current() {
282+
Ok(s) => s,
283+
Err(_) => return,
284+
};
285+
let pct_idle = current.idle_since(prev);
286+
*prev = current;
287+
self.last_cpu_recording = now;
288+
let dur = d_as_f64(now.duration_since(self.start));
289+
self.cpu_usage.push((dur, 100.0 - pct_idle));
290+
}
291+
256292
/// Call this when all units are finished.
257293
pub fn finished(&mut self) -> CargoResult<()> {
258294
if !self.enabled {
@@ -442,6 +478,11 @@ impl<'a, 'cfg> Timings<'a, 'cfg> {
442478
"const CONCURRENCY_DATA = {};",
443479
serde_json::to_string_pretty(&self.concurrency)?
444480
)?;
481+
writeln!(
482+
f,
483+
"const CPU_USAGE = {};",
484+
serde_json::to_string_pretty(&self.cpu_usage)?
485+
)?;
445486
Ok(())
446487
}
447488

src/cargo/util/cpu.rs

Lines changed: 223 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,223 @@
1+
use std::io;
2+
3+
pub struct State(imp::State);
4+
5+
impl State {
6+
/// Captures the current state of all CPUs on the system.
7+
///
8+
/// The `State` returned here isn't too meaningful in terms of
9+
/// interpretation across platforms, but it can be compared to previous
10+
/// states to get a meaningful cross-platform number.
11+
pub fn current() -> io::Result<State> {
12+
imp::current().map(State)
13+
}
14+
15+
/// Returns the percentage of time CPUs were idle from the current state
16+
/// relative to the previous state, as a percentage from 0.0 to 100.0.
17+
///
18+
/// This function will return, as a percentage, the amount of time that the
19+
/// entire system was idle between the `previous` state and this own state.
20+
/// This can be useful to compare two snapshots in time of CPU usage to see
21+
/// how the CPU usage compares between the two.
22+
pub fn idle_since(&self, previous: &State) -> f64 {
23+
imp::pct_idle(&previous.0, &self.0)
24+
}
25+
}
26+
27+
#[cfg(target_os = "linux")]
28+
mod imp {
29+
use std::fs::File;
30+
use std::io::{self, Read};
31+
32+
pub struct State {
33+
user: u64,
34+
nice: u64,
35+
system: u64,
36+
idle: u64,
37+
iowait: u64,
38+
irq: u64,
39+
softirq: u64,
40+
steal: u64,
41+
guest: u64,
42+
guest_nice: u64,
43+
}
44+
45+
pub fn current() -> io::Result<State> {
46+
let mut state = String::new();
47+
File::open("/proc/stat")?.read_to_string(&mut state)?;
48+
let mut parts = state.lines().next().unwrap().split_whitespace();
49+
if parts.next() != Some("cpu") {
50+
return Err(io::Error::new(
51+
io::ErrorKind::Other,
52+
"cannot parse /proc/stat",
53+
));
54+
}
55+
56+
Ok(State {
57+
user: parts.next().unwrap().parse::<u64>().unwrap(),
58+
nice: parts.next().unwrap().parse::<u64>().unwrap(),
59+
system: parts.next().unwrap().parse::<u64>().unwrap(),
60+
idle: parts.next().unwrap().parse::<u64>().unwrap(),
61+
iowait: parts.next().unwrap().parse::<u64>().unwrap(),
62+
irq: parts.next().unwrap().parse::<u64>().unwrap(),
63+
softirq: parts.next().unwrap().parse::<u64>().unwrap(),
64+
steal: parts.next().unwrap().parse::<u64>().unwrap(),
65+
guest: parts.next().unwrap().parse::<u64>().unwrap(),
66+
guest_nice: parts.next().unwrap().parse::<u64>().unwrap(),
67+
})
68+
}
69+
70+
pub fn pct_idle(prev: &State, next: &State) -> f64 {
71+
let user = next.user - prev.user;
72+
let nice = next.nice - prev.nice;
73+
let system = next.system - prev.system;
74+
let idle = next.idle - prev.idle;
75+
let iowait = next.iowait - prev.iowait;
76+
let irq = next.irq - prev.irq;
77+
let softirq = next.softirq - prev.softirq;
78+
let steal = next.steal - prev.steal;
79+
let guest = next.guest - prev.guest;
80+
let guest_nice = next.guest_nice - prev.guest_nice;
81+
let total =
82+
user + nice + system + idle + iowait + irq + softirq + steal + guest + guest_nice;
83+
84+
(idle as f64) / (total as f64) * 100.0
85+
}
86+
}
87+
88+
#[cfg(target_os = "macos")]
89+
#[allow(bad_style)]
90+
mod imp {
91+
use std::io;
92+
use std::ptr;
93+
use std::slice;
94+
95+
type host_t = u32;
96+
type mach_port_t = u32;
97+
type processor_flavor_t = i32;
98+
type natural_t = u32;
99+
type processor_info_array_t = *mut i32;
100+
type mach_msg_type_number_t = i32;
101+
type kern_return_t = i32;
102+
103+
const PROESSOR_CPU_LOAD_INFO: processor_flavor_t = 2;
104+
const CPU_STATE_USER: usize = 0;
105+
const CPU_STATE_SYSTEM: usize = 1;
106+
const CPU_STATE_IDLE: usize = 2;
107+
const CPU_STATE_NICE: usize = 3;
108+
109+
extern "C" {
110+
fn mach_host_self() -> mach_port_t;
111+
fn host_processor_info(
112+
host: host_t,
113+
flavor: processor_flavor_t,
114+
out_processor_count: *mut natural_t,
115+
out_processor_info: *mut processor_info_array_t,
116+
out_processor_infoCnt: *mut mach_msg_type_number_t,
117+
) -> kern_return_t;
118+
}
119+
120+
pub struct State {
121+
user: u64,
122+
system: u64,
123+
idle: u64,
124+
nice: u64,
125+
}
126+
127+
pub fn current() -> io::Result<State> {
128+
unsafe {
129+
let mut num_cpus_u = 0;
130+
let mut cpu_info = ptr::null_mut();
131+
let mut cpu_info_cnt = 0;
132+
let err = host_processor_info(
133+
mach_host_self(),
134+
PROESSOR_CPU_LOAD_INFO,
135+
&mut num_cpus_u,
136+
&mut cpu_info,
137+
&mut cpu_info_cnt,
138+
);
139+
if err != 0 {
140+
return Err(io::Error::last_os_error());
141+
}
142+
let cpu_info = slice::from_raw_parts(cpu_info, cpu_info_cnt as usize);
143+
let mut ret = State {
144+
user: 0,
145+
system: 0,
146+
idle: 0,
147+
nice: 0,
148+
};
149+
for chunk in cpu_info.chunks(num_cpus_u as usize) {
150+
ret.user += chunk[CPU_STATE_USER] as u64;
151+
ret.system += chunk[CPU_STATE_SYSTEM] as u64;
152+
ret.idle += chunk[CPU_STATE_IDLE] as u64;
153+
ret.nice += chunk[CPU_STATE_NICE] as u64;
154+
}
155+
Ok(ret)
156+
}
157+
}
158+
159+
pub fn pct_idle(prev: &State, next: &State) -> f64 {
160+
let user = next.user - prev.user;
161+
let system = next.system - prev.system;
162+
let idle = next.idle - prev.idle;
163+
let nice = next.nice - prev.nice;
164+
let total = user + system + idle + nice;
165+
(idle as f64) / (total as f64) * 100.0
166+
}
167+
}
168+
169+
#[cfg(windows)]
170+
mod imp {
171+
use std::io;
172+
use std::mem;
173+
use winapi::shared::minwindef::*;
174+
use winapi::um::processthreadsapi::*;
175+
176+
pub struct State {
177+
idle: FILETIME,
178+
kernel: FILETIME,
179+
user: FILETIME,
180+
}
181+
182+
pub fn current() -> io::Result<State> {
183+
unsafe {
184+
let mut ret = mem::zeroed::<State>();
185+
let r = GetSystemTimes(&mut ret.idle, &mut ret.kernel, &mut ret.user);
186+
if r != 0 {
187+
Ok(ret)
188+
} else {
189+
Err(io::Error::last_os_error())
190+
}
191+
}
192+
}
193+
194+
pub fn pct_idle(prev: &State, next: &State) -> f64 {
195+
fn to_u64(a: &FILETIME) -> u64 {
196+
((a.dwHighDateTime as u64) << 32) | (a.dwLowDateTime as u64)
197+
}
198+
199+
let idle = to_u64(&next.idle) - to_u64(&prev.idle);
200+
let kernel = to_u64(&next.kernel) - to_u64(&prev.kernel);
201+
let user = to_u64(&next.user) - to_u64(&prev.user);
202+
let total = user + kernel;
203+
(idle as f64) / (total as f64) * 100.0
204+
}
205+
}
206+
207+
#[cfg(not(any(target_os = "linux", target_os = "macos", windows)))]
208+
mod imp {
209+
use std::io;
210+
211+
pub struct State;
212+
213+
pub fn current() -> io::Result<State> {
214+
Err(io::Error::new(
215+
io::ErrorKind::Other,
216+
"unsupported platform to learn CPU state",
217+
))
218+
}
219+
220+
pub fn pct_idle(_prev: &State, _next: &State) -> f64 {
221+
unimplemented!()
222+
}
223+
}

src/cargo/util/mod.rs

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -33,6 +33,7 @@ mod canonical_url;
3333
mod cfg;
3434
pub mod command_prelude;
3535
pub mod config;
36+
pub mod cpu;
3637
mod dependency_queue;
3738
pub mod diagnostic_server;
3839
pub mod errors;

0 commit comments

Comments
 (0)