[CLOUD-319] Make mixlib-log an optional dependency

This change makes mixlib-log an optional dependency. When it's available
in the LOAD_PATH it will be used by default, otherwise, all logging will
will be forwarded to a null logger that does nothing. This is useful for
cases where small utilities can consume mixlib-authentication and not
have to pull in additional gems.

Signed-off-by: Ryan Cragun <me@ryan.ec>

9 files changed, 111 insertions, 27 deletions

diff --git a/Gemfile b/Gemfile
index 3297f71..25103b0 100644
--- a/Gemfile
+++ b/Gemfile
@@ -3,4 +3,5 @@ gemspec
 
 group(:development) do
   gem "pry"
+  gem "mixlib-log"
 end
diff --git a/lib/mixlib/authentication.rb b/lib/mixlib/authentication.rb
index 443512e..b27e06e 100644
--- a/lib/mixlib/authentication.rb
+++ b/lib/mixlib/authentication.rb
@@ -16,12 +16,13 @@
 # limitations under the License.
 #
 
-require "mixlib/log"
-
 module Mixlib
   module Authentication
     DEFAULT_SERVER_API_VERSION = "0"
 
+    attr_accessor :logger
+    module_function :logger, :logger=
+
     class AuthenticationError < StandardError
     end
 
@@ -29,10 +30,17 @@ module Mixlib
     end
 
     class Log
-      extend Mixlib::Log
     end
 
-    Log.level = :error
+    begin
+      require "mixlib/log"
+      Mixlib::Authentication::Log.extend(Mixlib::Log)
+    rescue LoadError
+      require "mixlib/authentication/null_logger"
+      Mixlib::Authentication::Log.extend(Mixlib::Authentication::NullLogger)
+    end
 
+    Mixlib::Authentication.logger = Mixlib::Authentication::Log
+    Mixlib::Authentication.logger.level = :error
   end
 end
diff --git a/lib/mixlib/authentication/null_logger.rb b/lib/mixlib/authentication/null_logger.rb
new file mode 100644
index 0000000..2bc9e31
--- /dev/null
+++ b/lib/mixlib/authentication/null_logger.rb
@@ -0,0 +1,24 @@
+module Mixlib
+  module Authentication
+    module NullLogger
+
+      attr_accessor :level
+
+      %i{debug info warn error fatal}.each do |method_name|
+        class_eval(<<-METHOD_DEFN, __FILE__, __LINE__)
+          def #{method_name}(msg=nil, &block)
+            true
+          end
+        METHOD_DEFN
+      end
+
+      %i{debug? info? warn? error? fatal?}.each do |method_name|
+        class_eval(<<-METHOD_DEFN, __FILE__, __LINE__)
+          def #{method_name}
+            false
+          end
+        METHOD_DEFN
+      end
+    end
+  end
+end
diff --git a/lib/mixlib/authentication/signatureverification.rb b/lib/mixlib/authentication/signatureverification.rb
index 842fc1f..898e05b 100644
--- a/lib/mixlib/authentication/signatureverification.rb
+++ b/lib/mixlib/authentication/signatureverification.rb
@@ -76,7 +76,7 @@ module Mixlib
       # X-Ops-Content-Hash:
       # X-Ops-Authorization-#{line_number}
       def authenticate_request(user_secret, time_skew = (15 * 60))
-        Mixlib::Authentication::Log.debug "Initializing header auth : #{request.inspect}"
+        Mixlib::Authentication.logger.debug "Initializing header auth : #{request.inspect}"
 
         @user_secret       = user_secret
         @allowed_time_skew = time_skew # in seconds
@@ -150,14 +150,14 @@ module Mixlib
                            end
 
         # Keep the debug messages lined up so it's easy to scan them
-        Mixlib::Authentication::Log.debug("Verifying request signature:")
-        Mixlib::Authentication::Log.debug(" Expected Block is: '#{candidate_block}'")
-        Mixlib::Authentication::Log.debug("Decrypted block is: '#{request_decrypted_block}'")
-        Mixlib::Authentication::Log.debug("Signatures match? : '#{@valid_signature}'")
+        Mixlib::Authentication.logger.debug("Verifying request signature:")
+        Mixlib::Authentication.logger.debug(" Expected Block is: '#{candidate_block}'")
+        Mixlib::Authentication.logger.debug("Decrypted block is: '#{request_decrypted_block}'")
+        Mixlib::Authentication.logger.debug("Signatures match? : '#{@valid_signature}'")
 
         @valid_signature
       rescue => e
-        Mixlib::Authentication::Log.debug("Failed to verify request signature: #{e.class.name}: #{e.message}")
+        Mixlib::Authentication.logger.debug("Failed to verify request signature: #{e.class.name}: #{e.message}")
         @valid_signature = false
       end
 
@@ -169,9 +169,9 @@ module Mixlib
         @valid_content_hash = (content_hash == hashed_body)
 
         # Keep the debug messages lined up so it's easy to scan them
-        Mixlib::Authentication::Log.debug("Expected content hash is: '#{hashed_body}'")
-        Mixlib::Authentication::Log.debug(" Request Content Hash is: '#{content_hash}'")
-        Mixlib::Authentication::Log.debug("           Hashes match?: #{@valid_content_hash}")
+        Mixlib::Authentication.logger.debug("Expected content hash is: '#{hashed_body}'")
+        Mixlib::Authentication.logger.debug(" Request Content Hash is: '#{content_hash}'")
+        Mixlib::Authentication.logger.debug("           Hashes match?: #{@valid_content_hash}")
 
         @valid_content_hash
       end
@@ -211,11 +211,11 @@ module Mixlib
           # Any file that's included in the request is hashed if it's there. Otherwise,
           # we hash the body.
           if file_param
-            Mixlib::Authentication::Log.debug "Digesting file_param: '#{file_param.inspect}'"
+            Mixlib::Authentication.logger.debug "Digesting file_param: '#{file_param.inspect}'"
             @hashed_body = digester.hash_file(file_param, digest)
           else
             body = request.raw_post
-            Mixlib::Authentication::Log.debug "Digesting body: '#{body}'"
+            Mixlib::Authentication.logger.debug "Digesting body: '#{body}'"
             @hashed_body = digester.hash_string(body, digest)
           end
         end
@@ -232,7 +232,7 @@ module Mixlib
       def timestamp_within_bounds?(time1, time2)
         time_diff = (time2 - time1).abs
         is_allowed = (time_diff < @allowed_time_skew)
-        Mixlib::Authentication::Log.debug "Request time difference: #{time_diff}, within #{@allowed_time_skew} seconds? : #{!!is_allowed}"
+        Mixlib::Authentication.logger.debug "Request time difference: #{time_diff}, within #{@allowed_time_skew} seconds? : #{!!is_allowed}"
         is_allowed
       end
     end
diff --git a/lib/mixlib/authentication/signedheaderauth.rb b/lib/mixlib/authentication/signedheaderauth.rb
index f107170..3119c87 100644
--- a/lib/mixlib/authentication/signedheaderauth.rb
+++ b/lib/mixlib/authentication/signedheaderauth.rb
@@ -115,7 +115,7 @@ module Mixlib
           header_hash[key] = signature_lines[idx]
         end
 
-        Mixlib::Authentication::Log.debug "Header hash: #{header_hash.inspect}"
+        Mixlib::Authentication.logger.debug "Header hash: #{header_hash.inspect}"
 
         header_hash
       end
@@ -166,7 +166,8 @@ module Mixlib
         # Hence, we're going to assume the one that is passed to sign is
         # the correct one and needs to passed through all the functions
         # that do any sort of digest.
-        if @hashed_body_digest != nil && @hashed_body_digest != digest
+        @hashed_body_digest = nil unless defined?(@hashed_body_digest)
+        if !@hashed_body_digest.nil? && @hashed_body_digest != digest
           raise "hashed_body must always be called with the same digest"
         else
           @hashed_body_digest = digest
@@ -235,7 +236,7 @@ module Mixlib
           memo[field_name.to_sym] = field_value.strip
           memo
         end
-        Mixlib::Authentication::Log.debug "Parsed signing description: #{parts.inspect}"
+        Mixlib::Authentication.logger.debug "Parsed signing description: #{parts.inspect}"
         parts
       end
 
@@ -246,7 +247,7 @@ module Mixlib
       # private
       def do_sign(private_key, digest, sign_algorithm, sign_version)
         string_to_sign = canonicalize_request(sign_algorithm, sign_version)
-        Mixlib::Authentication::Log.debug "String to sign: '#{string_to_sign}'"
+        Mixlib::Authentication.logger.debug "String to sign: '#{string_to_sign}'"
         case sign_version
         when "1.3"
           private_key.sign(digest.new, string_to_sign)
@@ -274,7 +275,7 @@ module Mixlib
 
       def server_api_version
         key = (self[:headers] || {}).keys.select do |k|
-          k.casecmp("x-ops-server-api-version").zero?
+          k.casecmp("x-ops-server-api-version") == 0
         end.first
         if key
           self[:headers][key]
diff --git a/mixlib-authentication.gemspec b/mixlib-authentication.gemspec
index 65cd629..0830546 100644
--- a/mixlib-authentication.gemspec
+++ b/mixlib-authentication.gemspec
@@ -12,9 +12,6 @@ Gem::Specification.new do |s|
   s.email = "info@chef.io"
   s.homepage = "https://www.chef.io"
 
-  # Uncomment this to add a dependency
-  s.add_dependency "mixlib-log"
-
   s.require_path = "lib"
   s.files = %w{LICENSE README.md Gemfile Rakefile NOTICE} + Dir.glob("*.gemspec") +
     Dir.glob("{lib,spec}/**/*", File::FNM_DOTMATCH).reject { |f| File.directory?(f) }
diff --git a/spec/mixlib/authentication/mixlib_authentication_spec.rb b/spec/mixlib/authentication/mixlib_authentication_spec.rb
index d0e8071..221e803 100644
--- a/spec/mixlib/authentication/mixlib_authentication_spec.rb
+++ b/spec/mixlib/authentication/mixlib_authentication_spec.rb
@@ -63,8 +63,7 @@ class MockFile
 end
 
 # Uncomment this to get some more info from the methods we're testing.
-#Mixlib::Authentication::Log.logger = Logger.new(STDERR)
-#Mixlib::Authentication::Log.level :debug
+#Mixlib::Authentication.logger.level = :debug
 
 describe "Mixlib::Authentication::SignedHeaderAuth" do
 
diff --git a/spec/mixlib/authentication/mixlib_log_missing_spec.rb b/spec/mixlib/authentication/mixlib_log_missing_spec.rb
new file mode 100644
index 0000000..4b12b12
--- /dev/null
+++ b/spec/mixlib/authentication/mixlib_log_missing_spec.rb
@@ -0,0 +1,55 @@
+describe "Mixlib::Authentication::Log" do
+  before do
+    Mixlib::Authentication.send(:remove_const, "DEFAULT_SERVER_API_VERSION")
+    Mixlib::Authentication.send(:remove_const, "Log")
+  end
+
+  context "without mixlib-log" do
+    before do
+      @mixlib_path = $LOAD_PATH.find { |p| p.match("mixlib-log") }
+      $LOAD_PATH.reject! { |p| p.match("mixlib-log") }
+
+      load "mixlib/authentication.rb"
+    end
+
+    after do
+      $LOAD_PATH.unshift(@mixlib_path)
+    end
+
+    it "uses MixlibLogMissing" do
+      expect(Mixlib::Authentication::Log.singleton_class.included_modules)
+        .to include(Mixlib::Authentication::NullLogger)
+    end
+
+    it "default log level is :error" do
+      expect(Mixlib::Authentication::Log.level).to eq(:error)
+    end
+
+    %w{debug info warn error fatal}.each do |level|
+      it "logs at level #{level}" do
+        expect(Mixlib::Authentication::Log).to receive(level).with("foo")
+
+        Mixlib::Authentication.logger.send(level, "foo")
+      end
+    end
+  end
+
+  context "with mixlib-log" do
+    before do
+      load "mixlib/authentication.rb"
+    end
+
+    it "uses Mixlib::Log" do
+      expect(Mixlib::Authentication::Log.singleton_class.included_modules)
+        .to include(Mixlib::Log)
+    end
+
+    %w{debug info warn error fatal}.each do |level|
+      it "forward #{level} to mixlib-log" do
+        expect(Mixlib::Authentication::Log.logger).to receive(level).with("foo")
+
+        Mixlib::Authentication.logger.send(level, "foo")
+      end
+    end
+  end
+end
diff --git a/spec/spec_helper.rb b/spec/spec_helper.rb
index fe03c12..be55155 100644
--- a/spec/spec_helper.rb
+++ b/spec/spec_helper.rb
@@ -18,6 +18,5 @@
 #
 
 $:.unshift File.expand_path(File.join(File.dirname(__FILE__), "..", "lib")) # lib in mixlib-authentication
-$:.unshift File.expand_path(File.join(File.dirname(__FILE__), "..", "..", "mixlib-log", "lib")) # mixlib-log/log
 
 require "rubygems"