src/librustc/util/profiling.rs

   1 // Copyright 2018 The Rust Project Developers. See the COPYRIGHT
   2 // file at the top-level directory of this distribution and at
   3 // http://rust-lang.org/COPYRIGHT.
   4 //
   5 // Licensed under the Apache License, Version 2.0 <LICENSE-APACHE or
   6 // http://www.apache.org/licenses/LICENSE-2.0> or the MIT license
   7 // <LICENSE-MIT or http://opensource.org/licenses/MIT>, at your
   8 // option. This file may not be copied, modified, or distributed
   9 // except according to those terms.
  10
  11 use session::config::Options;
  12
  13 use std::fs;
  14 use std::io::{self, StdoutLock, Write};
  15 use std::time::Instant;
  16
  17 #[derive(Clone, Copy, Debug, PartialEq, Eq, Hash)]
  18 pub enum ProfileCategory {
  19     Parsing,
  20     Expansion,
  21     TypeChecking,
  22     BorrowChecking,
  23     Codegen,
  24     Linking,
  25     Other,
  26 }
  27
  28 struct Categories<T> {
  29     parsing: T,
  30     expansion: T,
  31     type_checking: T,
  32     borrow_checking: T,
  33     codegen: T,
  34     linking: T,
  35     other: T,
  36 }
  37
  38 impl<T: Default> Categories<T> {
  39     fn new() -> Categories<T> {
  40         Categories {
  41             parsing: T::default(),
  42             expansion: T::default(),
  43             type_checking: T::default(),
  44             borrow_checking: T::default(),
  45             codegen: T::default(),
  46             linking: T::default(),
  47             other: T::default(),
  48         }
  49     }
  50 }
  51
  52 impl<T> Categories<T> {
  53     fn get(&self, category: ProfileCategory) -> &T {
  54         match category {
  55             ProfileCategory::Parsing => &self.parsing,
  56             ProfileCategory::Expansion => &self.expansion,
  57             ProfileCategory::TypeChecking => &self.type_checking,
  58             ProfileCategory::BorrowChecking => &self.borrow_checking,
  59             ProfileCategory::Codegen => &self.codegen,
  60             ProfileCategory::Linking => &self.linking,
  61             ProfileCategory::Other => &self.other,
  62         }
  63     }
  64
  65     fn set(&mut self, category: ProfileCategory, value: T) {
  66         match category {
  67             ProfileCategory::Parsing => self.parsing = value,
  68             ProfileCategory::Expansion => self.expansion = value,
  69             ProfileCategory::TypeChecking => self.type_checking = value,
  70             ProfileCategory::BorrowChecking => self.borrow_checking = value,
  71             ProfileCategory::Codegen => self.codegen = value,
  72             ProfileCategory::Linking => self.linking = value,
  73             ProfileCategory::Other => self.other = value,
  74         }
  75     }
  76 }
  77
  78 struct CategoryData {
  79     times: Categories<u64>,
  80     query_counts: Categories<(u64, u64)>,
  81 }
  82
  83 impl CategoryData {
  84     fn new() -> CategoryData {
  85         CategoryData {
  86             times: Categories::new(),
  87             query_counts: Categories::new(),
  88         }
  89     }
  90
  91     fn print(&self, lock: &mut StdoutLock) {
  92         macro_rules! p {
  93             ($name:tt, $rustic_name:ident) => {
  94                 let (hits, total) = self.query_counts.$rustic_name;
  95                 let (hits, total) = if total > 0 {
  96                     (format!("{:.2}",
  97                      (((hits as f32) / (total as f32)) * 100.0)), total.to_string())
  98                 } else {
  99                     ("".into(), "".into())
 100                 };
 101
 102                 writeln!(
 103                    lock,
 104                    "| {0: <16} | {1: <14} | {2: <14} | {3: <8} |",
 105                    $name,
 106                    self.times.$rustic_name / 1_000_000,
 107                    total,
 108                    hits
 109                 ).unwrap();
 110             };
 111         }
 112
 113         writeln!(lock, "| Phase            | Time (ms)      | Queries        | Hits (%) |")
 114             .unwrap();
 115         writeln!(lock, "| ---------------- | -------------- | -------------- | -------- |")
 116             .unwrap();
 117
 118         p!("Parsing", parsing);
 119         p!("Expansion", expansion);
 120         p!("TypeChecking", type_checking);
 121         p!("BorrowChecking", borrow_checking);
 122         p!("Codegen", codegen);
 123         p!("Linking", linking);
 124         p!("Other", other);
 125     }
 126
 127     fn json(&self) -> String {
 128         macro_rules! j {
 129             ($category:tt, $rustic_name:ident) => {{
 130                 let (hits, total) = self.query_counts.$rustic_name;
 131
 132                 format!(
 133                     "{{ \"category\": {}, \"time_ms\": {},
 134                         \"query_count\": {}, \"query_hits\": {} }}",
 135                     stringify!($category),
 136                     self.times.$rustic_name / 1_000_000,
 137                     total,
 138                     format!("{:.2}", (((hits as f32) / (total as f32)) * 100.0))
 139                 )
 140             }}
 141         }
 142
 143         format!("[
 144             {},
 145             {},
 146             {},
 147             {},
 148             {},
 149             {},
 150             {}
 151         ]",
 152             j!("Parsing", parsing),
 153             j!("Expansion", expansion),
 154             j!("TypeChecking", type_checking),
 155             j!("BorrowChecking", borrow_checking),
 156             j!("Codegen", codegen),
 157             j!("Linking", linking),
 158             j!("Other", other)
 159         )
 160     }
 161 }
 162
 163 pub struct SelfProfiler {
 164     timer_stack: Vec<ProfileCategory>,
 165     data: CategoryData,
 166     current_timer: Instant,
 167 }
 168
 169 impl SelfProfiler {
 170     pub fn new() -> SelfProfiler {
 171         let mut profiler = SelfProfiler {
 172             timer_stack: Vec::new(),
 173             data: CategoryData::new(),
 174             current_timer: Instant::now(),
 175         };
 176
 177         profiler.start_activity(ProfileCategory::Other);
 178
 179         profiler
 180     }
 181
 182     pub fn start_activity(&mut self, category: ProfileCategory) {
 183         match self.timer_stack.last().cloned() {
 184             None => {
 185                 self.current_timer = Instant::now();
 186             },
 187             Some(current_category) if current_category == category => {
 188                 //since the current category is the same as the new activity's category,
 189                 //we don't need to do anything with the timer, we just need to push it on the stack
 190             }
 191             Some(current_category) => {
 192                 let elapsed = self.stop_timer();
 193
 194                 //record the current category's time
 195                 let new_time = self.data.times.get(current_category) + elapsed;
 196                 self.data.times.set(current_category, new_time);
 197             }
 198         }
 199
 200         //push the new category
 201         self.timer_stack.push(category);
 202     }
 203
 204     pub fn record_query(&mut self, category: ProfileCategory) {
 205         let (hits, total) = *self.data.query_counts.get(category);
 206         self.data.query_counts.set(category, (hits, total + 1));
 207     }
 208
 209     pub fn record_query_hit(&mut self, category: ProfileCategory) {
 210         let (hits, total) = *self.data.query_counts.get(category);
 211         self.data.query_counts.set(category, (hits + 1, total));
 212     }
 213
 214     pub fn end_activity(&mut self, category: ProfileCategory) {
 215         match self.timer_stack.pop() {
 216             None => bug!("end_activity() was called but there was no running activity"),
 217             Some(c) =>
 218                 assert!(
 219                     c == category,
 220                     "end_activity() was called but a different activity was running"),
 221         }
 222
 223         //check if the new running timer is in the same category as this one
 224         //if it is, we don't need to do anything
 225         if let Some(c) = self.timer_stack.last() {
 226             if *c == category {
 227                 return;
 228             }
 229         }
 230
 231         //the new timer is different than the previous,
 232         //so record the elapsed time and start a new timer
 233         let elapsed = self.stop_timer();
 234         let new_time = self.data.times.get(category) + elapsed;
 235         self.data.times.set(category, new_time);
 236     }
 237
 238     fn stop_timer(&mut self) -> u64 {
 239         let elapsed = self.current_timer.elapsed();
 240
 241         self.current_timer = Instant::now();
 242
 243         (elapsed.as_secs() * 1_000_000_000) + (elapsed.subsec_nanos() as u64)
 244     }
 245
 246     pub fn print_results(&mut self, opts: &Options) {
 247         self.end_activity(ProfileCategory::Other);
 248
 249         assert!(
 250             self.timer_stack.is_empty(),
 251             "there were timers running when print_results() was called");
 252
 253         let out = io::stdout();
 254         let mut lock = out.lock();
 255
 256         let crate_name =
 257             opts.crate_name
 258             .as_ref()
 259             .map(|n| format!(" for {}", n))
 260             .unwrap_or_default();
 261
 262         writeln!(lock, "Self profiling results{}:", crate_name).unwrap();
 263         writeln!(lock).unwrap();
 264
 265         self.data.print(&mut lock);
 266
 267         writeln!(lock).unwrap();
 268         writeln!(lock, "Optimization level: {:?}", opts.optimize).unwrap();
 269
 270         let incremental = if opts.incremental.is_some() { "on" } else { "off" };
 271         writeln!(lock, "Incremental: {}", incremental).unwrap();
 272     }
 273
 274     pub fn save_results(&self, opts: &Options) {
 275         let category_data = self.data.json();
 276         let compilation_options =
 277             format!("{{ \"optimization_level\": \"{:?}\", \"incremental\": {} }}",
 278                     opts.optimize,
 279                     if opts.incremental.is_some() { "true" } else { "false" });
 280
 281         let json = format!("{{ \"category_data\": {}, \"compilation_options\": {} }}",
 282                         category_data,
 283                         compilation_options);
 284
 285         fs::write("self_profiler_results.json", json).unwrap();
 286     }
 287 }