Auto merge of #938 - jhod0:time_phases, r=fitzgen

Time phases

New module `time_phases` with an RAII timer which prints to stderr, and command-line flag `--time-phases` to enable it.

Fixes #933

5 files changed, 107 insertions, 1 deletions

diff --git a/src/codegen/mod.rs b/src/codegen/mod.rs
index 553dd24f..f47787af 100644
--- a/src/codegen/mod.rs
+++ b/src/codegen/mod.rs
@@ -3479,6 +3479,7 @@ impl CodeGenerator for ObjCInterface {
 
 pub fn codegen(context: &mut BindgenContext) -> Vec<P<ast::Item>> {
     context.gen(|context| {
+        let _t = context.timer("codegen");
         let counter = Cell::new(0);
         let mut result = CodegenResult::new(&counter);
 
diff --git a/src/ir/context.rs b/src/ir/context.rs
index 3f503fdd..788c3f98 100644
--- a/src/ir/context.rs
+++ b/src/ir/context.rs
@@ -15,6 +15,7 @@ use super::module::{Module, ModuleKind};
 use super::template::{TemplateInstantiation, TemplateParameters};
 use super::traversal::{self, Edge, ItemTraversal};
 use super::ty::{FloatKind, Type, TypeKind};
+use super::super::time::Timer;
 use BindgenOptions;
 use callbacks::ParseCallbacks;
 use cexpr;
@@ -406,6 +407,13 @@ impl<'ctx> BindgenContext<'ctx> {
         me
     }
 
+    /// Creates a timer for the current bindgen phase. If time_phases is `true`,
+    /// the timer will print to stderr when it is dropped, otherwise it will do
+    /// nothing.
+    pub fn timer<'a>(&self, name: &'a str) -> Timer<'a> {
+        Timer::new(name).with_output(self.options.time_phases)
+    }
+
     /// Get the stack of partially parsed types that we are in the middle of
     /// parsing.
     pub fn currently_parsed_types(&self) -> &[PartialType] {
@@ -731,6 +739,7 @@ impl<'ctx> BindgenContext<'ctx> {
     /// Iterate over all items and replace any item that has been named in a
     /// `replaces="SomeType"` annotation with the replacement type.
     fn process_replacements(&mut self) {
+        let _t = self.timer("process_replacements");
         if self.replacements.is_empty() {
             debug!("No replacements to process");
             return;
@@ -993,6 +1002,7 @@ impl<'ctx> BindgenContext<'ctx> {
 
     /// Compute whether the type has vtable.
     fn compute_has_vtable(&mut self) {
+        let _t = self.timer("compute_has_vtable");
         assert!(self.have_vtable.is_none());
         self.have_vtable = Some(analyze::<HasVtableAnalysis>(self));
     }
@@ -1011,6 +1021,7 @@ impl<'ctx> BindgenContext<'ctx> {
 
     /// Compute whether the type has a destructor.
     fn compute_has_destructor(&mut self) {
+        let _t = self.timer("compute_has_destructor");
         assert!(self.have_destructor.is_none());
         self.have_destructor = Some(analyze::<HasDestructorAnalysis>(self));
     }
@@ -1026,6 +1037,7 @@ impl<'ctx> BindgenContext<'ctx> {
     }
 
     fn find_used_template_parameters(&mut self) {
+        let _t = self.timer("find_used_template_parameters");
         if self.options.whitelist_recursively {
             let used_params = analyze::<UsedTemplateParameters>(self);
             self.used_template_parameters = Some(used_params);
@@ -1869,6 +1881,7 @@ impl<'ctx> BindgenContext<'ctx> {
         assert!(self.in_codegen_phase());
         assert!(self.current_module == self.root_module);
         assert!(self.whitelisted.is_none());
+        let _t = self.timer("compute_whitelisted_and_codegen_items");
 
         let roots = {
             let mut roots = self.items()
@@ -1991,6 +2004,7 @@ impl<'ctx> BindgenContext<'ctx> {
 
     /// Compute whether we can derive debug.
     fn compute_cannot_derive_debug(&mut self) {
+        let _t = self.timer("compute_cannot_derive_debug");
         assert!(self.cannot_derive_debug.is_none());
         if self.options.derive_debug {
             self.cannot_derive_debug = Some(analyze::<CannotDeriveDebug>(self));
@@ -2012,6 +2026,7 @@ impl<'ctx> BindgenContext<'ctx> {
 
     /// Compute whether we can derive default.
     fn compute_cannot_derive_default(&mut self) {
+        let _t = self.timer("compute_cannot_derive_default");
         assert!(self.cannot_derive_default.is_none());
         if self.options.derive_default {
             self.cannot_derive_default =
@@ -2034,12 +2049,14 @@ impl<'ctx> BindgenContext<'ctx> {
 
     /// Compute whether we can derive copy.
     fn compute_cannot_derive_copy(&mut self) {
+        let _t = self.timer("compute_cannot_derive_copy");
         assert!(self.cannot_derive_copy.is_none());
         self.cannot_derive_copy = Some(analyze::<CannotDeriveCopy>(self));
     }
 
     /// Compute whether we can derive hash.
     fn compute_cannot_derive_hash(&mut self) {
+        let _t = self.timer("compute_cannot_derive_hash");
         assert!(self.cannot_derive_hash.is_none());
         if self.options.derive_hash {
             self.cannot_derive_hash = Some(analyze::<CannotDeriveHash>(self));
@@ -2062,6 +2079,7 @@ impl<'ctx> BindgenContext<'ctx> {
     /// Compute whether we can derive PartialEq. This method is also used in calculating
     /// whether we can derive Eq
     fn compute_cannot_derive_partialeq_or_eq(&mut self) {
+        let _t = self.timer("compute_cannot_derive_partialeq_or_eq");
         assert!(self.cannot_derive_partialeq.is_none());
         if self.options.derive_partialeq || self.options.derive_eq {
             self.cannot_derive_partialeq = Some(analyze::<CannotDerivePartialEq>(self));
@@ -2097,6 +2115,7 @@ impl<'ctx> BindgenContext<'ctx> {
 
     /// Compute whether the type has type parameter in array.
     fn compute_has_type_param_in_array(&mut self) {
+        let _t = self.timer("compute_has_type_param_in_array");
         assert!(self.has_type_param_in_array.is_none());
         self.has_type_param_in_array =
             Some(analyze::<HasTypeParameterInArray>(self));
@@ -2116,6 +2135,7 @@ impl<'ctx> BindgenContext<'ctx> {
 
     /// Compute whether the type has float.
     fn compute_has_float(&mut self) {
+        let _t = self.timer("compute_has_float");
         assert!(self.has_float.is_none());
         if self.options.derive_eq {
             self.has_float = Some(analyze::<HasFloat>(self));
diff --git a/src/lib.rs b/src/lib.rs
index d5dbefae..af50f0e9 100644
--- a/src/lib.rs
+++ b/src/lib.rs
@@ -64,6 +64,7 @@ mod features;
 mod ir;
 mod parse;
 mod regex_set;
+mod time;
 
 pub mod callbacks;
 
@@ -278,6 +279,10 @@ impl Builder {
             output_vector.push("--with-derive-eq".into());
         }
 
+        if self.options.time_phases {
+            output_vector.push("--time-phases".into());
+        }
+
         if !self.options.generate_comments {
             output_vector.push("--no-doc-comments".into());
         }
@@ -774,6 +779,13 @@ impl Builder {
         self
     }
 
+    /// Set whether or not to time bindgen phases, and print
+    /// information to stderr.
+    pub fn time_phases(mut self, doit: bool) -> Self {
+        self.options.time_phases = doit;
+        self
+    }
+
     /// Emit Clang AST.
     pub fn emit_clang_ast(mut self) -> Builder {
         self.options.emit_ast = true;
@@ -1122,6 +1134,9 @@ pub struct BindgenOptions {
     /// An optional prefix for the "raw" types, like `c_int`, `c_void`...
     pub ctypes_prefix: Option<String>,
 
+    /// Whether to time the bindgen phases.
+    pub time_phases: bool,
+
     /// True if we should generate constant names that are **directly** under
     /// namespaces.
     pub namespaced_constants: bool,
@@ -1280,6 +1295,7 @@ impl Default for BindgenOptions {
             objc_extern_crate: false,
             enable_mangling: true,
             prepend_enum_name: true,
+            time_phases: false,
             rustfmt_bindings: false,
             rustfmt_configuration_file: None,
         }
@@ -1403,8 +1419,13 @@ impl<'ctx> Bindings<'ctx> {
             options.clang_args.push(f.name.to_str().unwrap().to_owned())
         }
 
+        let time_phases = options.time_phases;
         let mut context = BindgenContext::new(options);
-        try!(parse(&mut context));
+        {
+            let _t = time::Timer::new("parse")
+                                  .with_output(time_phases);
+            try!(parse(&mut context));
+        }
 
         let module = ast::Mod {
             inner: span,
diff --git a/src/options.rs b/src/options.rs
index 780959e2..c6f5c010 100644
--- a/src/options.rs
+++ b/src/options.rs
@@ -107,6 +107,9 @@ where
                       ::std::os::raw.")
                 .value_name("prefix")
                 .takes_value(true),
+            Arg::with_name("time-phases")
+                .long("time-phases")
+                .help("Time the different bindgen phases and print to stderr"),
             // All positional arguments after the end of options marker, `--`
             Arg::with_name("clang-args")
                 .multiple(true),
@@ -340,6 +343,10 @@ where
         builder = builder.prepend_enum_name(false);
     }
 
+    if matches.is_present("time-phases") {
+        builder = builder.time_phases(true);
+    }
+
     if let Some(prefix) = matches.value_of("ctypes-prefix") {
         builder = builder.ctypes_prefix(prefix);
     }
diff --git a/src/time.rs b/src/time.rs
new file mode 100644
index 00000000..ebbac702
--- /dev/null
+++ b/src/time.rs
@@ -0,0 +1,57 @@
+use std::io::{self, Write};
+use std::time::{Instant, Duration};
+
+
+/// RAII timer to measure how long phases take.
+#[derive(Debug)]
+pub struct Timer<'a> {
+    output: bool,
+    name: &'a str,
+    start: Instant,
+}
+
+
+impl<'a> Timer<'a> {
+    /// Creates a Timer with the given name, and starts it. By default,
+    /// will print to stderr when it is `drop`'d
+    pub fn new(name: &'a str) -> Self {
+        Timer {
+            output: true,
+            name,
+            start: Instant::now()
+        }
+    }
+
+    /// Sets whether or not the Timer will print a mesage
+    /// when it is dropped.
+    pub fn with_output(mut self, output: bool) -> Self {
+        self.output = output;
+        self
+    }
+
+    /// Returns the time elapsed since the timer's creation
+    pub fn elapsed(&self) -> Duration {
+        Instant::now() - self.start
+    }
+
+    fn print_elapsed(&mut self) {
+        if self.output {
+            let elapsed = self.elapsed();
+            let time = (elapsed.as_secs() as f32)
+                       + (elapsed.subsec_nanos() as f32) / 1e9;
+            let stderr = io::stderr();
+            // Arbitrary output format, subject to change.
+            writeln!(stderr.lock(),
+                     "  time: {:.3} ms.\t{}",
+                     time, self.name)
+                     .expect("timer write should not fail");
+        }
+    }
+}
+
+
+impl<'a> Drop for Timer<'a> {
+    fn drop(&mut self) {
+        self.print_elapsed();
+    }
+}