Move idempotency logs to debug

This was discussed in the last Chef Triage meeting.

In the great move to trace logging, which is great, idempotency check
logs moved to trace, which defeats the purpose. The goal is to keep
"internal chef" logging in trace so that when users are trying to figure
out why their cookbook isn't acting as expected they can look at debug
without having to see all the other cruft. But "here's why I didn't
install the package you said to install" is table-steaks "I'm trying to
debug my cookbook."

This moves those logs back to debug. There were a variety of cases where
logging was pretty nonstandard in other ways, but to keep this PR
scoped, I didn't change those.

I did fix a few related logging issues:
* A few warns that should have been debug in windows_task
* A few places where there was basically no logging whatsoever, I put a
  few of the "I did X" logs to 'debug' (from trace). It coudl be argued
  some of those should be 'info', but that's a bigger change that I
  didn't want to put into this PR

Signed-off-by: Phil Dibowitz <phil@ipom.com>

9 files changed, 18 insertions, 18 deletions

diff --git a/spec/unit/provider/cron_spec.rb b/spec/unit/provider/cron_spec.rb
index 76f170312e..9a276bfffd 100644
--- a/spec/unit/provider/cron_spec.rb
+++ b/spec/unit/provider/cron_spec.rb
@@ -719,7 +719,7 @@ describe Chef::Provider::Cron do
 
         it "should log nothing changed" do
           expect(logger).to receive(:trace).with("Found cron '#{@new_resource.name}'")
-          expect(logger).to receive(:trace).with("Skipping existing cron entry '#{@new_resource.name}'")
+          expect(logger).to receive(:debug).with("#{@new_resource}: Skipping existing cron entry")
           @provider.run_action(:create)
         end
       end
diff --git a/spec/unit/provider/group/gpasswd_spec.rb b/spec/unit/provider/group/gpasswd_spec.rb
index adc6efb5a6..98deb9dd69 100644
--- a/spec/unit/provider/group/gpasswd_spec.rb
+++ b/spec/unit/provider/group/gpasswd_spec.rb
@@ -68,7 +68,7 @@ describe Chef::Provider::Group::Gpasswd, "modify_group_members" do
       end
 
       it "logs a message and sets group's members to 'none'" do
-        expect(logger).to receive(:trace).with("group[wheel] setting group members to: none")
+        expect(logger).to receive(:debug).with("group[wheel] setting group members to: none")
         expect(@provider).to receive(:shell_out_compacted!).with("gpasswd", "-M", "", "wheel")
         @provider.modify_group_members
       end
@@ -88,7 +88,7 @@ describe Chef::Provider::Group::Gpasswd, "modify_group_members" do
 
     describe "when the resource specifies group members" do
       it "should log an appropriate debug message" do
-        expect(logger).to receive(:trace).with("group[wheel] setting group members to: lobster, rage, fist")
+        expect(logger).to receive(:debug).with("group[wheel] setting group members to: lobster, rage, fist")
         allow(@provider).to receive(:shell_out_compacted!)
         @provider.modify_group_members
       end
diff --git a/spec/unit/provider/group/groupmod_spec.rb b/spec/unit/provider/group/groupmod_spec.rb
index 5a7d1ada77..9961d32bc5 100644
--- a/spec/unit/provider/group/groupmod_spec.rb
+++ b/spec/unit/provider/group/groupmod_spec.rb
@@ -64,7 +64,7 @@ describe Chef::Provider::Group::Groupmod do
         end
 
         it "logs a message and sets group's members to 'none', then removes existing group members" do
-          expect(logger).to receive(:trace).with("group[wheel] setting group members to: none")
+          expect(logger).to receive(:debug).with("group[wheel] setting group members to: none")
           expect(@provider).to receive(:shell_out_compacted!).with("group", "mod", "-n", "wheel_bak", "wheel")
           expect(@provider).to receive(:shell_out_compacted!).with("group", "add", "-g", "123", "-o", "wheel")
           expect(@provider).to receive(:shell_out_compacted!).with("group", "del", "wheel_bak")
@@ -79,7 +79,7 @@ describe Chef::Provider::Group::Groupmod do
         end
 
         it "logs a message and does not modify group membership" do
-          expect(logger).to receive(:trace).with("group[wheel] not changing group members, the group has no members to add")
+          expect(logger).to receive(:debug).with("group[wheel] not changing group members, the group has no members to add")
           expect(@provider).not_to receive(:shell_out_compacted!)
           @provider.manage_group
         end
diff --git a/spec/unit/provider/group/pw_spec.rb b/spec/unit/provider/group/pw_spec.rb
index f46bb9cb48..b6d6942a83 100644
--- a/spec/unit/provider/group/pw_spec.rb
+++ b/spec/unit/provider/group/pw_spec.rb
@@ -96,7 +96,7 @@ describe Chef::Provider::Group::Pw do
       end
 
       it "should log an appropriate message" do
-        expect(logger).to receive(:trace).with("group[wheel] removing group members: all,your,base")
+        expect(logger).to receive(:debug).with("group[wheel] removing group members: all,your,base")
         @provider.set_members_options
       end
 
@@ -112,7 +112,7 @@ describe Chef::Provider::Group::Pw do
       end
 
       it "should log an appropriate debug message" do
-        expect(logger).to receive(:trace).with("group[wheel] adding group members: all,your,base")
+        expect(logger).to receive(:debug).with("group[wheel] adding group members: all,your,base")
         @provider.set_members_options
       end
 
diff --git a/spec/unit/provider/package/apt_spec.rb b/spec/unit/provider/package/apt_spec.rb
index 45d6d16229..cf50c124a9 100644
--- a/spec/unit/provider/package/apt_spec.rb
+++ b/spec/unit/provider/package/apt_spec.rb
@@ -579,7 +579,7 @@ describe Chef::Provider::Package::Apt do
         ).and_return(instance_double(
           Mixlib::ShellOut, stdout: "irssi"
         ))
-        expect(logger).to receive(:trace).with("#{@provider.new_resource} is already locked")
+        expect(logger).to receive(:debug).with("#{@provider.new_resource} is already locked")
 
         @provider.action_lock
       end
@@ -600,7 +600,7 @@ describe Chef::Provider::Package::Apt do
         ).and_return(instance_double(
           Mixlib::ShellOut, stdout: ""
         ))
-        expect(logger).to receive(:trace).with("#{@provider.new_resource} is already unlocked")
+        expect(logger).to receive(:debug).with("#{@provider.new_resource} is already unlocked")
 
         @provider.action_unlock
       end
diff --git a/spec/unit/provider/package/deb_spec.rb b/spec/unit/provider/package/deb_spec.rb
index da06b2d1b6..46867fc573 100644
--- a/spec/unit/provider/package/deb_spec.rb
+++ b/spec/unit/provider/package/deb_spec.rb
@@ -66,7 +66,7 @@ describe Chef::Provider::Package::Deb do
       it "does not reconfigure the package if the package is not installed" do
         allow(provider).to receive(:get_current_versions).and_return(nil)
         allow(provider.load_current_resource).to receive(:version).and_return(nil)
-        expect(logger).to receive(:trace).with("apt_package[emacs] is NOT installed - nothing to do")
+        expect(logger).to receive(:debug).with("apt_package[emacs] is NOT installed - nothing to do")
         expect(provider).not_to receive(:reconfig_package)
         provider.run_action(:reconfig)
         expect(new_resource).not_to be_updated_by_last_action
@@ -75,7 +75,7 @@ describe Chef::Provider::Package::Deb do
       it "does not reconfigure the package if no response_file is given" do
         allow(provider).to receive(:get_current_versions).and_return("1.0")
         allow(new_resource).to receive(:response_file).and_return(nil)
-        expect(logger).to receive(:trace).with("apt_package[emacs] no response_file provided - nothing to do")
+        expect(logger).to receive(:debug).with("apt_package[emacs] no response_file provided - nothing to do")
         expect(provider).not_to receive(:reconfig_package)
         provider.run_action(:reconfig)
         expect(new_resource).not_to be_updated_by_last_action
@@ -86,7 +86,7 @@ describe Chef::Provider::Package::Deb do
         allow(new_resource).to receive(:response_file).and_return(true)
         expect(provider).to receive(:get_preseed_file).and_return(false)
         allow(provider).to receive(:preseed_package).and_return(false)
-        expect(logger).to receive(:trace).with("apt_package[emacs] preseeding has not changed - nothing to do")
+        expect(logger).to receive(:debug).with("apt_package[emacs] preseeding has not changed - nothing to do")
         expect(provider).not_to receive(:reconfig_package)
         provider.run_action(:reconfig)
         expect(new_resource).not_to be_updated_by_last_action
diff --git a/spec/unit/provider/service/macosx_spec.rb b/spec/unit/provider/service/macosx_spec.rb
index 6cc0f88725..adf1192165 100644
--- a/spec/unit/provider/service/macosx_spec.rb
+++ b/spec/unit/provider/service/macosx_spec.rb
@@ -259,7 +259,7 @@ describe Chef::Provider::Service::Macosx do
 
             it "shows warning message if service is already running" do
               allow(current_resource).to receive(:running).and_return(true)
-              expect(logger).to receive(:trace).with("macosx_service[#{service_name}] already running, not starting")
+              expect(logger).to receive(:debug).with("macosx_service[#{service_name}] already running, not starting")
 
               provider.start_service
             end
@@ -291,7 +291,7 @@ describe Chef::Provider::Service::Macosx do
 
             it "shows warning message if service is not running" do
               allow(current_resource).to receive(:running).and_return(false)
-              expect(logger).to receive(:trace).with("macosx_service[#{service_name}] not running, not stopping")
+              expect(logger).to receive(:debug).with("macosx_service[#{service_name}] not running, not stopping")
 
               provider.stop_service
             end
diff --git a/spec/unit/provider/service/windows_spec.rb b/spec/unit/provider/service/windows_spec.rb
index b3a85715a8..08d4b2a620 100644
--- a/spec/unit/provider/service/windows_spec.rb
+++ b/spec/unit/provider/service/windows_spec.rb
@@ -254,7 +254,7 @@ describe Chef::Provider::Service::Windows, "load_current_resource" do
       end
 
       it "logs debug message" do
-        expect(logger).to receive(:trace).with("windows_service[#{chef_service_name}] already exists - nothing to do")
+        expect(logger).to receive(:debug).with("windows_service[#{chef_service_name}] already exists - nothing to do")
         provider.action_create
       end
 
@@ -334,7 +334,7 @@ describe Chef::Provider::Service::Windows, "load_current_resource" do
       end
 
       it "logs debug message" do
-        expect(logger).to receive(:trace).with("windows_service[#{chef_service_name}] does not exist - nothing to do")
+        expect(logger).to receive(:debug).with("windows_service[#{chef_service_name}] does not exist - nothing to do")
         provider.action_delete
       end
 
diff --git a/spec/unit/provider/zypper_repository_spec.rb b/spec/unit/provider/zypper_repository_spec.rb
index f0686874e6..950022080a 100644
--- a/spec/unit/provider/zypper_repository_spec.rb
+++ b/spec/unit/provider/zypper_repository_spec.rb
@@ -96,7 +96,7 @@ describe Chef::Provider::ZypperRepository do
     it "skips key import if gpgautoimportkeys is false" do
       new_resource.gpgautoimportkeys(false)
       expect(provider).to receive(:declare_resource)
-      expect(logger).to receive(:trace)
+      expect(logger).to receive(:debug)
       provider.run_action(:create)
     end
   end
@@ -169,7 +169,7 @@ describe Chef::Provider::ZypperRepository do
 
   describe "#install_gpg_key" do
     it "skips installing the key if a nil value for key is passed" do
-      expect(logger).to receive(:trace)
+      expect(logger).to receive(:debug)
       provider.install_gpg_key(nil)
     end
   end