Merge pull request #1056 from chef/timing

Add plugin timing information in debug mode

2 files changed, 27 insertions, 19 deletions

diff --git a/lib/ohai/application.rb b/lib/ohai/application.rb
index 586a275d..3b648e9a 100644
--- a/lib/ohai/application.rb
+++ b/lib/ohai/application.rb
@@ -20,6 +20,7 @@ require "chef-config/workstation_config_loader"
 require "ohai"
 require "ohai/log"
 require "mixlib/cli"
+require "benchmark"
 
 class Ohai::Application
   include Mixlib::CLI
@@ -74,8 +75,11 @@ class Ohai::Application
   end
 
   def run
-    configure_ohai
-    run_application
+    elapsed = Benchmark.measure do
+      configure_ohai
+      run_application
+    end
+    Ohai::Log.debug("Ohai took #{elapsed.total} total seconds to run.")
   end
 
   def configure_ohai
diff --git a/lib/ohai/runner.rb b/lib/ohai/runner.rb
index 93ec46a3..6368cbe3 100644
--- a/lib/ohai/runner.rb
+++ b/lib/ohai/runner.rb
@@ -18,6 +18,7 @@
 #
 
 require "ohai/dsl"
+require "benchmark"
 
 module Ohai
   class Runner
@@ -33,26 +34,29 @@ module Ohai
     # If force is set to true, then this plugin and its dependencies
     # will be run even if they have been run before.
     def run_plugin(plugin)
-      unless plugin.kind_of?(Ohai::DSL::Plugin)
-        raise Ohai::Exceptions::InvalidPlugin, "Invalid plugin #{plugin} (must be an Ohai::DSL::Plugin or subclass)"
-      end
+      elapsed = Benchmark.measure do
+        unless plugin.kind_of?(Ohai::DSL::Plugin)
+          raise Ohai::Exceptions::InvalidPlugin, "Invalid plugin #{plugin} (must be an Ohai::DSL::Plugin or subclass)"
+        end
 
-      begin
-        case plugin.version
-        when :version7
-          run_v7_plugin(plugin)
-        when :version6
-          run_v6_plugin(plugin)
-        else
-          raise Ohai::Exceptions::InvalidPlugin, "Invalid plugin version #{plugin.version} for plugin #{plugin}"
+        begin
+          case plugin.version
+          when :version7
+            run_v7_plugin(plugin)
+          when :version6
+            run_v6_plugin(plugin)
+          else
+            raise Ohai::Exceptions::InvalidPlugin, "Invalid plugin version #{plugin.version} for plugin #{plugin}"
+          end
+        rescue Ohai::Exceptions::Error
+          raise
+        rescue SystemExit # abort or exit from plug-in should exit Ohai with failure code
+          raise
+        rescue Exception, Errno::ENOENT => e
+          Ohai::Log.debug("Plugin #{plugin.name} threw exception #{e.inspect} #{e.backtrace.join("\n")}")
         end
-      rescue Ohai::Exceptions::Error
-        raise
-      rescue SystemExit # abort or exit from plug-in should exit Ohai with failure code
-        raise
-      rescue Exception, Errno::ENOENT => e
-        Ohai::Log.debug("Plugin #{plugin.name} threw exception #{e.inspect} #{e.backtrace.join("\n")}")
       end
+      Ohai::Log.debug("Plugin #{plugin.name} took #{elapsed.total} seconds to run.")
     end
 
     def run_v6_plugin(plugin)