From a4ca79d7a3a6e0a992c9710cbf6c7445534cad44 Mon Sep 17 00:00:00 2001 From: Joel Handwell Date: Tue, 25 Aug 2015 16:07:23 -0400 Subject: Human friendly elapsed time in log --- lib/chef/formatters/doc.rb | 14 +++++++++++--- 1 file changed, 11 insertions(+), 3 deletions(-) diff --git a/lib/chef/formatters/doc.rb b/lib/chef/formatters/doc.rb index 614cc44e6d..deeb5d3e96 100644 --- a/lib/chef/formatters/doc.rb +++ b/lib/chef/formatters/doc.rb @@ -26,7 +26,15 @@ class Chef end def elapsed_time - end_time - start_time + time = end_time - start_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 hour %M minutes %S seconds") + end + message end def run_start(version) @@ -66,7 +74,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 #{elapsed_time}" if total_audits > 0 puts_line " #{successful_audits}/#{total_audits} controls succeeded" end @@ -78,7 +86,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 #{elapsed_time}" if total_audits > 0 puts_line " #{successful_audits} controls succeeded" end -- cgit v1.2.1 From f2de463a69508cb91e952f3034f7e951c9ab1af7 Mon Sep 17 00:00:00 2001 From: Joel Handwell Date: Tue, 25 Aug 2015 18:08:16 -0400 Subject: Add unit tests for elapsed_time --- Gemfile | 1 + lib/chef/formatters/doc.rb | 2 +- spec/unit/formatters/doc_spec.rb | 35 +++++++++++++++++++++++++++++++++++ 3 files changed, 37 insertions(+), 1 deletion(-) diff --git a/Gemfile b/Gemfile index af0bef493c..0f547c1645 100644 --- a/Gemfile +++ b/Gemfile @@ -14,6 +14,7 @@ group(:development, :test) do gem "simplecov" gem 'rack', "~> 1.5.1" gem 'cheffish', "~> 1.3" + gem 'timecop' gem 'ruby-shadow', :platforms => :ruby unless RUBY_PLATFORM.downcase.match(/(aix|cygwin)/) end diff --git a/lib/chef/formatters/doc.rb b/lib/chef/formatters/doc.rb index deeb5d3e96..93039d6171 100644 --- a/lib/chef/formatters/doc.rb +++ b/lib/chef/formatters/doc.rb @@ -32,7 +32,7 @@ class Chef elsif time < 3600 then message = Time.at(time).utc.strftime("%M minutes %S seconds") else - message = Time.at(time).utc.strftime("%H hour %M minutes %S seconds") + message = Time.at(time).utc.strftime("%H hours %M minutes %S seconds") end message end diff --git a/spec/unit/formatters/doc_spec.rb b/spec/unit/formatters/doc_spec.rb index eb98f5abd3..f208508aba 100644 --- a/spec/unit/formatters/doc_spec.rb +++ b/spec/unit/formatters/doc_spec.rb @@ -18,12 +18,21 @@ # require 'spec_helper' +require 'timecop' describe Chef::Formatters::Base do let(:out) { StringIO.new } let(:err) { StringIO.new } + before do + Timecop.freeze(Time.local(2008, 9, 9, 9, 9, 9)) + end + + after do + Timecop.return + end + subject(:formatter) { Chef::Formatters::Doc.new(out, err) } it "prints a policyfile's name and revision ID" do @@ -49,4 +58,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 + f = Chef::Formatters::Doc.new(out, err) + Timecop.freeze(2008, 9, 9, 9, 9, 19) do + f.run_completed(nil) + expect(f.elapsed_time).to include("10 seconds") + expect(f.elapsed_time).not_to include("minutes") + expect(f.elapsed_time).not_to include("hours") + end + end + + it "prints minutes and seconds when elapsed time is more than 60 seconds" do + f = Chef::Formatters::Doc.new(out, err) + Timecop.freeze(2008, 9, 9, 9, 19, 19) do + f.run_completed(nil) + expect(f.elapsed_time).to include("10 minutes 10 seconds") + expect(f.elapsed_time).not_to include("hours") + end + end + + it "prints hours, minutes and seconds when elapsed time is more than 3600 seconds" do + f = Chef::Formatters::Doc.new(out, err) + Timecop.freeze(2008, 9, 9, 19, 19, 19) do + f.run_completed(nil) + expect(f.elapsed_time).to include("10 hours 10 minutes 10 seconds") + end + end end -- cgit v1.2.1 From 5f6589f3c05c965d3c555613bf21c635978a36be Mon Sep 17 00:00:00 2001 From: Joel Handwell Date: Tue, 25 Aug 2015 19:05:04 -0400 Subject: Refactor to reduce duplicated instancialization --- spec/unit/formatters/doc_spec.rb | 31 ++++++++++++++----------------- 1 file changed, 14 insertions(+), 17 deletions(-) diff --git a/spec/unit/formatters/doc_spec.rb b/spec/unit/formatters/doc_spec.rb index f208508aba..15af595020 100644 --- a/spec/unit/formatters/doc_spec.rb +++ b/spec/unit/formatters/doc_spec.rb @@ -25,15 +25,15 @@ describe Chef::Formatters::Base do let(:out) { StringIO.new } let(:err) { StringIO.new } - before do - Timecop.freeze(Time.local(2008, 9, 9, 9, 9, 9)) - end - after do Timecop.return end - subject(:formatter) { Chef::Formatters::Doc.new(out, err) } + subject(:formatter) { + Timecop.freeze(Time.local(2008, 9, 9, 9, 9, 9)) do + Chef::Formatters::Doc.new(out, err) + end + } it "prints a policyfile's name and revision ID" do minimal_policyfile = { @@ -59,29 +59,26 @@ describe Chef::Formatters::Base do end it "prints only seconds when elapsed time is less than 60 seconds" do - f = Chef::Formatters::Doc.new(out, err) Timecop.freeze(2008, 9, 9, 9, 9, 19) do - f.run_completed(nil) - expect(f.elapsed_time).to include("10 seconds") - expect(f.elapsed_time).not_to include("minutes") - expect(f.elapsed_time).not_to include("hours") + formatter.run_completed(nil) + expect(formatter.elapsed_time).to include("10 seconds") + expect(formatter.elapsed_time).not_to include("minutes") + expect(formatter.elapsed_time).not_to include("hours") end end it "prints minutes and seconds when elapsed time is more than 60 seconds" do - f = Chef::Formatters::Doc.new(out, err) Timecop.freeze(2008, 9, 9, 9, 19, 19) do - f.run_completed(nil) - expect(f.elapsed_time).to include("10 minutes 10 seconds") - expect(f.elapsed_time).not_to include("hours") + formatter.run_completed(nil) + expect(formatter.elapsed_time).to include("10 minutes 10 seconds") + expect(formatter.elapsed_time).not_to include("hours") end end it "prints hours, minutes and seconds when elapsed time is more than 3600 seconds" do - f = Chef::Formatters::Doc.new(out, err) Timecop.freeze(2008, 9, 9, 19, 19, 19) do - f.run_completed(nil) - expect(f.elapsed_time).to include("10 hours 10 minutes 10 seconds") + formatter.run_completed(nil) + expect(formatter.elapsed_time).to include("10 hours 10 minutes 10 seconds") end end end -- cgit v1.2.1 From 850bded619ac14e62bed15b85cc34d6ef3b99202 Mon Sep 17 00:00:00 2001 From: Joel Handwell Date: Mon, 31 Aug 2015 08:31:55 -0400 Subject: Keep elapsed_time and add pretty_elapsed_time --- lib/chef/formatters/doc.rb | 10 +++++++--- spec/unit/formatters/doc_spec.rb | 15 +++++++++------ 2 files changed, 16 insertions(+), 9 deletions(-) diff --git a/lib/chef/formatters/doc.rb b/lib/chef/formatters/doc.rb index 93039d6171..2b0161667b 100644 --- a/lib/chef/formatters/doc.rb +++ b/lib/chef/formatters/doc.rb @@ -26,7 +26,11 @@ class Chef end def elapsed_time - time = end_time - start_time + 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 @@ -74,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}" + 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 @@ -86,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}" + 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 15af595020..7db5ebc348 100644 --- a/spec/unit/formatters/doc_spec.rb +++ b/spec/unit/formatters/doc_spec.rb @@ -61,24 +61,27 @@ describe Chef::Formatters::Base do it "prints only seconds when elapsed time is less than 60 seconds" do Timecop.freeze(2008, 9, 9, 9, 9, 19) do formatter.run_completed(nil) - expect(formatter.elapsed_time).to include("10 seconds") - expect(formatter.elapsed_time).not_to include("minutes") - expect(formatter.elapsed_time).not_to include("hours") + 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 end it "prints minutes and seconds when elapsed time is more than 60 seconds" do Timecop.freeze(2008, 9, 9, 9, 19, 19) do formatter.run_completed(nil) - expect(formatter.elapsed_time).to include("10 minutes 10 seconds") - expect(formatter.elapsed_time).not_to include("hours") + 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 end it "prints hours, minutes and seconds when elapsed time is more than 3600 seconds" do Timecop.freeze(2008, 9, 9, 19, 19, 19) do formatter.run_completed(nil) - expect(formatter.elapsed_time).to include("10 hours 10 minutes 10 seconds") + expect(formatter.elapsed_time).to eql(36610.0) + expect(formatter.pretty_elapsed_time).to include("10 hours 10 minutes 10 seconds") end end end -- cgit v1.2.1 From 51e98c798e455c9e758d9ace22d1391b7aad596c Mon Sep 17 00:00:00 2001 From: Joel Handwell Date: Tue, 1 Sep 2015 17:32:16 -0400 Subject: Remove Timecop dependency --- Gemfile | 1 - lib/chef/formatters/doc.rb | 2 +- spec/unit/formatters/doc_spec.rb | 47 ++++++++++++++++------------------------ 3 files changed, 20 insertions(+), 30 deletions(-) diff --git a/Gemfile b/Gemfile index 0f547c1645..af0bef493c 100644 --- a/Gemfile +++ b/Gemfile @@ -14,7 +14,6 @@ group(:development, :test) do gem "simplecov" gem 'rack', "~> 1.5.1" gem 'cheffish', "~> 1.3" - gem 'timecop' gem 'ruby-shadow', :platforms => :ruby unless RUBY_PLATFORM.downcase.match(/(aix|cygwin)/) end diff --git a/lib/chef/formatters/doc.rb b/lib/chef/formatters/doc.rb index 2b0161667b..70108f547b 100644 --- a/lib/chef/formatters/doc.rb +++ b/lib/chef/formatters/doc.rb @@ -33,7 +33,7 @@ class Chef time = elapsed_time if time < 60 then message = Time.at(time).utc.strftime("%S seconds") - elsif time < 3600 then + 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") diff --git a/spec/unit/formatters/doc_spec.rb b/spec/unit/formatters/doc_spec.rb index 7db5ebc348..7266afc320 100644 --- a/spec/unit/formatters/doc_spec.rb +++ b/spec/unit/formatters/doc_spec.rb @@ -18,22 +18,13 @@ # require 'spec_helper' -require 'timecop' describe Chef::Formatters::Base do let(:out) { StringIO.new } let(:err) { StringIO.new } - after do - Timecop.return - end - - subject(:formatter) { - Timecop.freeze(Time.local(2008, 9, 9, 9, 9, 9)) do - Chef::Formatters::Doc.new(out, err) - end - } + subject(:formatter) { Chef::Formatters::Doc.new(out, err) } it "prints a policyfile's name and revision ID" do minimal_policyfile = { @@ -59,29 +50,29 @@ describe Chef::Formatters::Base do end it "prints only seconds when elapsed time is less than 60 seconds" do - Timecop.freeze(2008, 9, 9, 9, 9, 19) do - 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 + @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 - Timecop.freeze(2008, 9, 9, 9, 19, 19) do - 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 + @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 - Timecop.freeze(2008, 9, 9, 19, 19, 19) do - 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 + @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 -- cgit v1.2.1