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 macro_rules! define_categories {
  18     ($($name:ident,)*) => {
  19         #[derive(Clone, Copy, Debug, PartialEq, Eq)]
  20         pub enum ProfileCategory {
  21             $($name),*
  22         }
  23
  24         #[allow(nonstandard_style)]
  25         struct Categories<T> {
  26             $($name: T),*
  27         }
  28
  29         impl<T: Default> Categories<T> {
  30             fn new() -> Categories<T> {
  31                 Categories {
  32                     $($name: T::default()),*
  33                 }
  34             }
  35         }
  36
  37         impl<T> Categories<T> {
  38             fn get(&self, category: ProfileCategory) -> &T {
  39                 match category {
  40                     $(ProfileCategory::$name => &self.$name),*
  41                 }
  42             }
  43
  44             fn set(&mut self, category: ProfileCategory, value: T) {
  45                 match category {
  46                     $(ProfileCategory::$name => self.$name = value),*
  47                 }
  48             }
  49         }
  50
  51         struct CategoryData {
  52             times: Categories<u64>,
  53             query_counts: Categories<(u64, u64)>,
  54         }
  55
  56         impl CategoryData {
  57             fn new() -> CategoryData {
  58                 CategoryData {
  59                     times: Categories::new(),
  60                     query_counts: Categories::new(),
  61                 }
  62             }
  63
  64             fn print(&self, lock: &mut StdoutLock<'_>) {
  65                 writeln!(lock, "| Phase            | Time (ms)      | Queries        | Hits (%) |")
  66                     .unwrap();
  67                 writeln!(lock, "| ---------------- | -------------- | -------------- | -------- |")
  68                     .unwrap();
  69
  70                 $(
  71                     let (hits, total) = self.query_counts.$name;
  72                     let (hits, total) = if total > 0 {
  73                         (format!("{:.2}",
  74                         (((hits as f32) / (total as f32)) * 100.0)), total.to_string())
  75                     } else {
  76                         (String::new(), String::new())
  77                     };
  78
  79                     writeln!(
  80                         lock,
  81                         "| {0: <16} | {1: <14} | {2: <14} | {3: <8} |",
  82                         stringify!($name),
  83                         self.times.$name / 1_000_000,
  84                         total,
  85                         hits
  86                     ).unwrap();
  87                 )*
  88             }
  89
  90             fn json(&self) -> String {
  91                 let mut json = String::from("[");
  92
  93                 $(
  94                     let (hits, total) = self.query_counts.$name;
  95
  96                     json.push_str(&format!(
  97                         "{{ \"category\": {}, \"time_ms\": {},
  98                             \"query_count\": {}, \"query_hits\": {} }}",
  99                         stringify!($name),
 100                         self.times.$name / 1_000_000,
 101                         total,
 102                         format!("{:.2}", (((hits as f32) / (total as f32)) * 100.0))
 103                     ));
 104                 )*
 105
 106                 json.push(']');
 107
 108                 json
 109             }
 110         }
 111     }
 112 }
 113
 114 define_categories! {
 115     Parsing,
 116     Expansion,
 117     TypeChecking,
 118     BorrowChecking,
 119     Codegen,
 120     Linking,
 121     Other,
 122 }
 123
 124 pub struct SelfProfiler {
 125     timer_stack: Vec<ProfileCategory>,
 126     data: CategoryData,
 127     current_timer: Instant,
 128 }
 129
 130 impl SelfProfiler {
 131     pub fn new() -> SelfProfiler {
 132         let mut profiler = SelfProfiler {
 133             timer_stack: Vec::new(),
 134             data: CategoryData::new(),
 135             current_timer: Instant::now(),
 136         };
 137
 138         profiler.start_activity(ProfileCategory::Other);
 139
 140         profiler
 141     }
 142
 143     pub fn start_activity(&mut self, category: ProfileCategory) {
 144         match self.timer_stack.last().cloned() {
 145             None => {
 146                 self.current_timer = Instant::now();
 147             },
 148             Some(current_category) if current_category == category => {
 149                 //since the current category is the same as the new activity's category,
 150                 //we don't need to do anything with the timer, we just need to push it on the stack
 151             }
 152             Some(current_category) => {
 153                 let elapsed = self.stop_timer();
 154
 155                 //record the current category's time
 156                 let new_time = self.data.times.get(current_category) + elapsed;
 157                 self.data.times.set(current_category, new_time);
 158             }
 159         }
 160
 161         //push the new category
 162         self.timer_stack.push(category);
 163     }
 164
 165     pub fn record_query(&mut self, category: ProfileCategory) {
 166         let (hits, total) = *self.data.query_counts.get(category);
 167         self.data.query_counts.set(category, (hits, total + 1));
 168     }
 169
 170     pub fn record_query_hit(&mut self, category: ProfileCategory) {
 171         let (hits, total) = *self.data.query_counts.get(category);
 172         self.data.query_counts.set(category, (hits + 1, total));
 173     }
 174
 175     pub fn end_activity(&mut self, category: ProfileCategory) {
 176         match self.timer_stack.pop() {
 177             None => bug!("end_activity() was called but there was no running activity"),
 178             Some(c) =>
 179                 assert!(
 180                     c == category,
 181                     "end_activity() was called but a different activity was running"),
 182         }
 183
 184         //check if the new running timer is in the same category as this one
 185         //if it is, we don't need to do anything
 186         if let Some(c) = self.timer_stack.last() {
 187             if *c == category {
 188                 return;
 189             }
 190         }
 191
 192         //the new timer is different than the previous,
 193         //so record the elapsed time and start a new timer
 194         let elapsed = self.stop_timer();
 195         let new_time = self.data.times.get(category) + elapsed;
 196         self.data.times.set(category, new_time);
 197     }
 198
 199     fn stop_timer(&mut self) -> u64 {
 200         let elapsed = self.current_timer.elapsed();
 201
 202         self.current_timer = Instant::now();
 203
 204         (elapsed.as_secs() * 1_000_000_000) + (elapsed.subsec_nanos() as u64)
 205     }
 206
 207     pub fn print_results(&mut self, opts: &Options) {
 208         self.end_activity(ProfileCategory::Other);
 209
 210         assert!(
 211             self.timer_stack.is_empty(),
 212             "there were timers running when print_results() was called");
 213
 214         let out = io::stdout();
 215         let mut lock = out.lock();
 216
 217         let crate_name =
 218             opts.crate_name
 219             .as_ref()
 220             .map(|n| format!(" for {}", n))
 221             .unwrap_or_default();
 222
 223         writeln!(lock, "Self profiling results{}:", crate_name).unwrap();
 224         writeln!(lock).unwrap();
 225
 226         self.data.print(&mut lock);
 227
 228         writeln!(lock).unwrap();
 229         writeln!(lock, "Optimization level: {:?}", opts.optimize).unwrap();
 230
 231         let incremental = if opts.incremental.is_some() { "on" } else { "off" };
 232         writeln!(lock, "Incremental: {}", incremental).unwrap();
 233     }
 234
 235     pub fn save_results(&self, opts: &Options) {
 236         let category_data = self.data.json();
 237         let compilation_options =
 238             format!("{{ \"optimization_level\": \"{:?}\", \"incremental\": {} }}",
 239                     opts.optimize,
 240                     if opts.incremental.is_some() { "true" } else { "false" });
 241
 242         let json = format!("{{ \"category_data\": {}, \"compilation_options\": {} }}",
 243                         category_data,
 244                         compilation_options);
 245
 246         fs::write("self_profiler_results.json", json).unwrap();
 247     }
 248 }