src/librustc/util/profiling.rs

   1 use std::collections::HashMap;
   2 use std::fs;
   3 use std::io::{BufWriter, Write};
   4 use std::mem;
   5 use std::process;
   6 use std::thread::ThreadId;
   7 use std::time::Instant;
   8
   9 use crate::session::config::Options;
  10
  11 #[derive(Clone, Copy, Debug, PartialEq, Eq, Ord, PartialOrd)]
  12 pub enum ProfileCategory {
  13     Parsing,
  14     Expansion,
  15     TypeChecking,
  16     BorrowChecking,
  17     Codegen,
  18     Linking,
  19     Other,
  20 }
  21
  22 #[derive(Clone, Copy, Debug, Eq, PartialEq)]
  23 pub enum ProfilerEvent {
  24     QueryStart { query_name: &'static str, category: ProfileCategory, time: Instant },
  25     QueryEnd { query_name: &'static str, category: ProfileCategory, time: Instant },
  26     GenericActivityStart { category: ProfileCategory, time: Instant },
  27     GenericActivityEnd { category: ProfileCategory, time: Instant },
  28     IncrementalLoadResultStart { query_name: &'static str, time: Instant },
  29     IncrementalLoadResultEnd { query_name: &'static str, time: Instant },
  30     QueryCacheHit { query_name: &'static str, category: ProfileCategory, time: Instant },
  31     QueryCount { query_name: &'static str, category: ProfileCategory, count: usize, time: Instant },
  32     QueryBlockedStart { query_name: &'static str, category: ProfileCategory, time: Instant },
  33     QueryBlockedEnd { query_name: &'static str, category: ProfileCategory, time: Instant },
  34 }
  35
  36 impl ProfilerEvent {
  37     fn timestamp(&self) -> Instant {
  38         use self::ProfilerEvent::*;
  39
  40         match self {
  41             QueryStart { time, .. } |
  42             QueryEnd { time, .. } |
  43             GenericActivityStart { time, .. } |
  44             GenericActivityEnd { time, .. } |
  45             QueryCacheHit { time, .. } |
  46             QueryCount { time, .. } |
  47             IncrementalLoadResultStart { time, .. } |
  48             IncrementalLoadResultEnd { time, .. } |
  49             QueryBlockedStart { time, .. } |
  50             QueryBlockedEnd { time, .. } => *time
  51         }
  52     }
  53 }
  54
  55 fn thread_id_to_u64(tid: ThreadId) -> u64 {
  56     unsafe { mem::transmute::<ThreadId, u64>(tid) }
  57 }
  58
  59 pub struct SelfProfiler {
  60     events: HashMap<ThreadId, Vec<ProfilerEvent>>,
  61 }
  62
  63 impl SelfProfiler {
  64     pub fn new() -> SelfProfiler {
  65         let mut profiler = SelfProfiler {
  66             events: HashMap::new(),
  67         };
  68
  69         profiler.start_activity(ProfileCategory::Other);
  70
  71         profiler
  72     }
  73
  74     #[inline]
  75     pub fn start_activity(&mut self, category: ProfileCategory) {
  76         self.record(ProfilerEvent::GenericActivityStart {
  77             category,
  78             time: Instant::now(),
  79         })
  80     }
  81
  82     #[inline]
  83     pub fn end_activity(&mut self, category: ProfileCategory) {
  84         self.record(ProfilerEvent::GenericActivityEnd {
  85             category,
  86             time: Instant::now(),
  87         })
  88     }
  89
  90     #[inline]
  91     pub fn record_computed_queries(
  92         &mut self,
  93         query_name: &'static str,
  94         category: ProfileCategory,
  95         count: usize)
  96         {
  97         self.record(ProfilerEvent::QueryCount {
  98             query_name,
  99             category,
 100             count,
 101             time: Instant::now(),
 102         })
 103     }
 104
 105     #[inline]
 106     pub fn record_query_hit(&mut self, query_name: &'static str, category: ProfileCategory) {
 107         self.record(ProfilerEvent::QueryCacheHit {
 108             query_name,
 109             category,
 110             time: Instant::now(),
 111         })
 112     }
 113
 114     #[inline]
 115     pub fn start_query(&mut self, query_name: &'static str, category: ProfileCategory) {
 116         self.record(ProfilerEvent::QueryStart {
 117             query_name,
 118             category,
 119             time: Instant::now(),
 120         });
 121     }
 122
 123     #[inline]
 124     pub fn end_query(&mut self, query_name: &'static str, category: ProfileCategory) {
 125         self.record(ProfilerEvent::QueryEnd {
 126             query_name,
 127             category,
 128             time: Instant::now(),
 129         })
 130     }
 131
 132     #[inline]
 133     pub fn incremental_load_result_start(&mut self, query_name: &'static str) {
 134         self.record(ProfilerEvent::IncrementalLoadResultStart {
 135             query_name,
 136             time: Instant::now(),
 137         })
 138     }
 139
 140     #[inline]
 141     pub fn incremental_load_result_end(&mut self, query_name: &'static str) {
 142         self.record(ProfilerEvent::IncrementalLoadResultEnd {
 143             query_name,
 144             time: Instant::now(),
 145         })
 146     }
 147
 148     #[inline]
 149     pub fn query_blocked_start(&mut self, query_name: &'static str, category: ProfileCategory) {
 150         self.record(ProfilerEvent::QueryBlockedStart {
 151             query_name,
 152             category,
 153             time: Instant::now(),
 154         })
 155     }
 156
 157     #[inline]
 158     pub fn query_blocked_end(&mut self, query_name: &'static str, category: ProfileCategory) {
 159         self.record(ProfilerEvent::QueryBlockedEnd {
 160             query_name,
 161             category,
 162             time: Instant::now(),
 163         })
 164     }
 165
 166     #[inline]
 167     fn record(&mut self, event: ProfilerEvent) {
 168         let thread_id = std::thread::current().id();
 169         let events = self.events.entry(thread_id).or_default();
 170
 171         events.push(event);
 172     }
 173
 174     pub fn dump_raw_events(&self, opts: &Options) {
 175         use self::ProfilerEvent::*;
 176
 177         //find the earliest Instant to use as t=0
 178         //when serializing the events, we'll calculate a Duration
 179         //using (instant - min_instant)
 180         let min_instant =
 181             self.events
 182                 .iter()
 183                 .map(|(_, values)| values[0].timestamp())
 184                 .min()
 185                 .unwrap();
 186
 187         let pid = process::id();
 188
 189         let filename =
 190             format!("{}.profile_events.json", opts.crate_name.clone().unwrap_or_default());
 191
 192         let mut file = BufWriter::new(fs::File::create(filename).unwrap());
 193
 194         let threads: Vec<_> =
 195             self.events
 196                 .keys()
 197                 .into_iter()
 198                 .map(|tid| format!("{}", thread_id_to_u64(*tid)))
 199                 .collect();
 200
 201         write!(file,
 202             "{{\
 203                 \"processes\": {{\
 204                     \"{}\": {{\
 205                         \"threads\": [{}],\
 206                         \"crate_name\": \"{}\",\
 207                         \"opt_level\": \"{:?}\",\
 208                         \"incremental\": {}\
 209                     }}\
 210                 }},\
 211                 \"events\": [\
 212              ",
 213             pid,
 214             threads.join(","),
 215             opts.crate_name.clone().unwrap_or_default(),
 216             opts.optimize,
 217             if opts.incremental.is_some() { "true" } else { "false" },
 218         ).unwrap();
 219
 220         let mut is_first = true;
 221         for (thread_id, events) in &self.events {
 222             let thread_id = thread_id_to_u64(*thread_id);
 223
 224             for event in events {
 225                 if is_first {
 226                     is_first = false;
 227                 } else {
 228                     writeln!(file, ",").unwrap();
 229                 }
 230
 231                 let (secs, nanos) = {
 232                     let duration = event.timestamp() - min_instant;
 233                     (duration.as_secs(), duration.subsec_nanos())
 234                 };
 235
 236                 match event {
 237                     QueryStart { query_name, category, time: _ } =>
 238                         write!(file,
 239                             "{{ \
 240                                 \"QueryStart\": {{ \
 241                                     \"query_name\": \"{}\",\
 242                                     \"category\": \"{:?}\",\
 243                                     \"time\": {{\
 244                                         \"secs\": {},\
 245                                         \"nanos\": {}\
 246                                     }},\
 247                                     \"thread_id\": {}\
 248                                 }}\
 249                             }}",
 250                             query_name,
 251                             category,
 252                             secs,
 253                             nanos,
 254                             thread_id,
 255                         ).unwrap(),
 256                     QueryEnd { query_name, category, time: _ } =>
 257                         write!(file,
 258                             "{{\
 259                                 \"QueryEnd\": {{\
 260                                     \"query_name\": \"{}\",\
 261                                     \"category\": \"{:?}\",\
 262                                     \"time\": {{\
 263                                         \"secs\": {},\
 264                                         \"nanos\": {}\
 265                                     }},\
 266                                     \"thread_id\": {}\
 267                                 }}\
 268                             }}",
 269                             query_name,
 270                             category,
 271                             secs,
 272                             nanos,
 273                             thread_id,
 274                         ).unwrap(),
 275                     GenericActivityStart { category, time: _ } =>
 276                         write!(file,
 277                             "{{
 278                                 \"GenericActivityStart\": {{\
 279                                     \"category\": \"{:?}\",\
 280                                     \"time\": {{\
 281                                         \"secs\": {},\
 282                                         \"nanos\": {}\
 283                                     }},\
 284                                     \"thread_id\": {}\
 285                                 }}\
 286                             }}",
 287                             category,
 288                             secs,
 289                             nanos,
 290                             thread_id,
 291                         ).unwrap(),
 292                     GenericActivityEnd { category, time: _ } =>
 293                         write!(file,
 294                             "{{\
 295                                 \"GenericActivityEnd\": {{\
 296                                     \"category\": \"{:?}\",\
 297                                     \"time\": {{\
 298                                         \"secs\": {},\
 299                                         \"nanos\": {}\
 300                                     }},\
 301                                     \"thread_id\": {}\
 302                                 }}\
 303                             }}",
 304                             category,
 305                             secs,
 306                             nanos,
 307                             thread_id,
 308                         ).unwrap(),
 309                     QueryCacheHit { query_name, category, time: _ } =>
 310                         write!(file,
 311                             "{{\
 312                                 \"QueryCacheHit\": {{\
 313                                     \"query_name\": \"{}\",\
 314                                     \"category\": \"{:?}\",\
 315                                     \"time\": {{\
 316                                         \"secs\": {},\
 317                                         \"nanos\": {}\
 318                                     }},\
 319                                     \"thread_id\": {}\
 320                                 }}\
 321                             }}",
 322                             query_name,
 323                             category,
 324                             secs,
 325                             nanos,
 326                             thread_id,
 327                         ).unwrap(),
 328                     QueryCount { query_name, category, count, time: _ } =>
 329                         write!(file,
 330                             "{{\
 331                                 \"QueryCount\": {{\
 332                                     \"query_name\": \"{}\",\
 333                                     \"category\": \"{:?}\",\
 334                                     \"count\": {},\
 335                                     \"time\": {{\
 336                                         \"secs\": {},\
 337                                         \"nanos\": {}\
 338                                     }},\
 339                                     \"thread_id\": {}\
 340                                 }}\
 341                             }}",
 342                             query_name,
 343                             category,
 344                             count,
 345                             secs,
 346                             nanos,
 347                             thread_id,
 348                         ).unwrap(),
 349                     IncrementalLoadResultStart { query_name, time: _ } =>
 350                         write!(file,
 351                             "{{\
 352                                 \"IncrementalLoadResultStart\": {{\
 353                                     \"query_name\": \"{}\",\
 354                                     \"time\": {{\
 355                                         \"secs\": {},\
 356                                         \"nanos\": {}\
 357                                     }},\
 358                                     \"thread_id\": {}\
 359                                 }}\
 360                             }}",
 361                             query_name,
 362                             secs,
 363                             nanos,
 364                             thread_id,
 365                         ).unwrap(),
 366                     IncrementalLoadResultEnd { query_name, time: _ } =>
 367                         write!(file,
 368                             "{{\
 369                                 \"IncrementalLoadResultEnd\": {{\
 370                                     \"query_name\": \"{}\",\
 371                                     \"time\": {{\
 372                                         \"secs\": {},\
 373                                         \"nanos\": {}\
 374                                     }},\
 375                                     \"thread_id\": {}\
 376                                 }}\
 377                             }}",
 378                             query_name,
 379                             secs,
 380                             nanos,
 381                             thread_id,
 382                         ).unwrap(),
 383                     QueryBlockedStart { query_name, category, time: _ } =>
 384                         write!(file,
 385                             "{{\
 386                                 \"QueryBlockedStart\": {{\
 387                                     \"query_name\": \"{}\",\
 388                                     \"category\": \"{:?}\",\
 389                                     \"time\": {{\
 390                                         \"secs\": {},\
 391                                         \"nanos\": {}\
 392                                     }},\
 393                                     \"thread_id\": {}\
 394                                 }}\
 395                             }}",
 396                             query_name,
 397                             category,
 398                             secs,
 399                             nanos,
 400                             thread_id,
 401                         ).unwrap(),
 402                     QueryBlockedEnd { query_name, category, time: _ } =>
 403                         write!(file,
 404                             "{{\
 405                                 \"QueryBlockedEnd\": {{\
 406                                     \"query_name\": \"{}\",\
 407                                     \"category\": \"{:?}\",\
 408                                     \"time\": {{\
 409                                         \"secs\": {},\
 410                                         \"nanos\": {}\
 411                                     }},\
 412                                     \"thread_id\": {}\
 413                                 }}\
 414                             }}",
 415                             query_name,
 416                             category,
 417                             secs,
 418                             nanos,
 419                             thread_id,
 420                         ).unwrap()
 421                 }
 422             }
 423         }
 424
 425         write!(file, "] }}").unwrap();
 426     }
 427 }