Merge pull request #3821 from joelhandwell/elapsed_time

Human friendly elapsed time in log

2 files changed, 40 insertions, 2 deletions

diff --git a/lib/chef/formatters/doc.rb b/lib/chef/formatters/doc.rb
index 614cc44e6d..70108f547b 100644
--- a/lib/chef/formatters/doc.rb
+++ b/lib/chef/formatters/doc.rb
@@ -29,6 +29,18 @@ class Chef
         end_time - start_time
       end
 
+      def pretty_elapsed_time
+        time = elapsed_time
+        if time < 60 then
+          message = Time.at(time).utc.strftime("%S seconds")
+        elsif time < 3600 then
+          message = Time.at(time).utc.strftime("%M minutes %S seconds")
+        else
+          message = Time.at(time).utc.strftime("%H hours %M minutes %S seconds")
+        end
+        message
+      end
+
       def run_start(version)
         puts_line "Starting Chef Client, version #{version}"
       end
@@ -66,7 +78,7 @@ class Chef
         if Chef::Config[:why_run]
           puts_line "Chef Client finished, #{@updated_resources}/#{total_resources} resources would have been updated"
         else
-          puts_line "Chef Client finished, #{@updated_resources}/#{total_resources} resources updated in #{elapsed_time} seconds"
+          puts_line "Chef Client finished, #{@updated_resources}/#{total_resources} resources updated in #{pretty_elapsed_time}"
           if total_audits > 0
             puts_line "  #{successful_audits}/#{total_audits} controls succeeded"
           end
@@ -78,7 +90,7 @@ class Chef
         if Chef::Config[:why_run]
           puts_line "Chef Client failed. #{@updated_resources} resources would have been updated"
         else
-          puts_line "Chef Client failed. #{@updated_resources} resources updated in #{elapsed_time} seconds"
+          puts_line "Chef Client failed. #{@updated_resources} resources updated in #{pretty_elapsed_time}"
           if total_audits > 0
             puts_line "  #{successful_audits} controls succeeded"
           end
diff --git a/spec/unit/formatters/doc_spec.rb b/spec/unit/formatters/doc_spec.rb
index eb98f5abd3..7266afc320 100644
--- a/spec/unit/formatters/doc_spec.rb
+++ b/spec/unit/formatters/doc_spec.rb
@@ -49,4 +49,30 @@ describe Chef::Formatters::Base do
     expect(out.string).to include("- apache2 (1.2.3")
   end
 
+  it "prints only seconds when elapsed time is less than 60 seconds" do
+    @now = Time.now
+    allow(Time).to receive(:now).and_return(@now, @now + 10.0)
+    formatter.run_completed(nil)
+    expect(formatter.elapsed_time).to eql(10.0)
+    expect(formatter.pretty_elapsed_time).to include("10 seconds")
+    expect(formatter.pretty_elapsed_time).not_to include("minutes")
+    expect(formatter.pretty_elapsed_time).not_to include("hours")
+  end
+
+  it "prints minutes and seconds when elapsed time is more than 60 seconds" do
+    @now = Time.now
+    allow(Time).to receive(:now).and_return(@now, @now + 610.0)
+    formatter.run_completed(nil)
+    expect(formatter.elapsed_time).to eql(610.0)
+    expect(formatter.pretty_elapsed_time).to include("10 minutes 10 seconds")
+    expect(formatter.pretty_elapsed_time).not_to include("hours")
+  end
+
+  it "prints hours, minutes and seconds when elapsed time is more than 3600 seconds" do
+    @now = Time.now
+    allow(Time).to receive(:now).and_return(@now, @now + 36610.0)
+    formatter.run_completed(nil)
+    expect(formatter.elapsed_time).to eql(36610.0)
+    expect(formatter.pretty_elapsed_time).to include("10 hours 10 minutes 10 seconds")
+  end
 end