require 'spec_helper'

require 'puppet/util/logging'

class LoggingTester
  include Puppet::Util::Logging
end

describe Puppet::Util::Logging do
  before do
    @logger = LoggingTester.new
  end

  Puppet::Util::Log.eachlevel do |level|
    it "should have a method for sending '#{level}' logs" do
      expect(@logger).to respond_to(level)
    end
  end

  it "should have a method for sending a log with a specified log level" do
    expect(@logger).to receive(:to_s).and_return("I'm a string!")
    expect(Puppet::Util::Log).to receive(:create).with(hash_including(source: "I'm a string!", level: "loglevel", message: "mymessage"))

    @logger.send_log "loglevel", "mymessage"
  end

  describe "when sending a log" do
    it "should use the Log's 'create' entrance method" do
      expect(Puppet::Util::Log).to receive(:create)

      @logger.notice "foo"
    end

    it "should send itself converted to a string as the log source" do
      expect(@logger).to receive(:to_s).and_return("I'm a string!")
      expect(Puppet::Util::Log).to receive(:create).with(hash_including(source: "I'm a string!"))

      @logger.notice "foo"
    end

    it "should queue logs sent without a specified destination" do
      Puppet::Util::Log.close_all
      expect(Puppet::Util::Log).to receive(:queuemessage)

      @logger.notice "foo"
    end

    it "should use the path of any provided resource type" do
      resource = Puppet::Type.type(:host).new :name => "foo"

      expect(resource).to receive(:path).and_return("/path/to/host".to_sym)

      expect(Puppet::Util::Log).to receive(:create).with(hash_including(source: "/path/to/host"))

      resource.notice "foo"
    end

    it "should use the path of any provided resource parameter" do
      resource = Puppet::Type.type(:host).new :name => "foo"

      param = resource.parameter(:name)

      expect(param).to receive(:path).and_return("/path/to/param".to_sym)

      expect(Puppet::Util::Log).to receive(:create).with(hash_including(source: "/path/to/param"))

      param.notice "foo"
    end

    it "should send the provided argument as the log message" do
      expect(Puppet::Util::Log).to receive(:create).with(hash_including(message: "foo"))

      @logger.notice "foo"
    end

    it "should join any provided arguments into a single string for the message" do
      expect(Puppet::Util::Log).to receive(:create).with(hash_including(message: "foo bar baz"))

      @logger.notice ["foo", "bar", "baz"]
    end

    [:file, :line, :tags].each do |attr|
      it "should include #{attr} if available" do
        @logger.singleton_class.send(:attr_accessor, attr)

        @logger.send(attr.to_s + "=", "myval")

        expect(Puppet::Util::Log).to receive(:create).with(hash_including(attr => "myval"))
        @logger.notice "foo"
      end
    end
  end

  describe "when sending a deprecation warning" do
    it "does not log a message when deprecation warnings are disabled" do
      expect(Puppet).to receive(:[]).with(:disable_warnings).and_return(%w[deprecations])
      expect(@logger).not_to receive(:warning)
      @logger.deprecation_warning 'foo'
    end

    it "logs the message with warn" do
      expect(@logger).to receive(:warning).with(/^foo\n/)
      @logger.deprecation_warning 'foo'
    end

    it "only logs each offending line once" do
      expect(@logger).to receive(:warning).with(/^foo\n/).once
      5.times { @logger.deprecation_warning 'foo' }
    end

    it "ensures that deprecations from same origin are logged if their keys differ" do
      expect(@logger).to receive(:warning).with(/deprecated foo/).exactly(5).times()
      5.times { |i| @logger.deprecation_warning('deprecated foo', :key => "foo#{i}") }
    end

    it "does not duplicate deprecations for a given key" do
      expect(@logger).to receive(:warning).with(/deprecated foo/).once
      5.times { @logger.deprecation_warning('deprecated foo', :key => 'foo-msg') }
    end

    it "only logs the first 100 messages" do
      (1..100).each { |i|
        expect(@logger).to receive(:warning).with(/^#{i}\n/).once
        # since the deprecation warning will only log each offending line once, we have to do some tomfoolery
        # here in order to make it think each of these calls is coming from a unique call stack; we're basically
        # mocking the method that it would normally use to find the call stack.
        expect(@logger).to receive(:get_deprecation_offender).and_return(["deprecation log count test ##{i}"])
        @logger.deprecation_warning i
      }
      expect(@logger).not_to receive(:warning).with(101)
      @logger.deprecation_warning 101
    end
  end

  describe "when sending a puppet_deprecation_warning" do
    it "requires file and line or key options" do
      expect do
        @logger.puppet_deprecation_warning("foo")
      end.to raise_error(Puppet::DevError, /Need either :file and :line, or :key/)
      expect do
        @logger.puppet_deprecation_warning("foo", :file => 'bar')
      end.to raise_error(Puppet::DevError, /Need either :file and :line, or :key/)
      expect do
        @logger.puppet_deprecation_warning("foo", :key => 'akey')
        @logger.puppet_deprecation_warning("foo", :file => 'afile', :line => 1)
      end.to_not raise_error
    end

    it "warns with file and line" do
      expect(@logger).to receive(:warning).with(/deprecated foo.*\(file: afile, line: 5\)/m)
      @logger.puppet_deprecation_warning("deprecated foo", :file => 'afile', :line => 5)
    end

    it "warns keyed from file and line" do
      expect(@logger).to receive(:warning).with(/deprecated foo.*\(file: afile, line: 5\)/m).once
      5.times do
        @logger.puppet_deprecation_warning("deprecated foo", :file => 'afile', :line => 5)
      end
    end

    it "warns with separate key only once regardless of file and line" do
      expect(@logger).to receive(:warning).with(/deprecated foo.*\(file: afile, line: 5\)/m).once
      @logger.puppet_deprecation_warning("deprecated foo", :key => 'some_key', :file => 'afile', :line => 5)
      @logger.puppet_deprecation_warning("deprecated foo", :key => 'some_key', :file => 'bfile', :line => 3)
    end

    it "warns with key but no file and line" do
      expect(@logger).to receive(:warning).with(/deprecated foo.*\(file: unknown, line: unknown\)/m)
      @logger.puppet_deprecation_warning("deprecated foo", :key => 'some_key')
    end
  end

  describe "when sending a warn_once" do
    before(:each) {
      @logger.clear_deprecation_warnings
    }

    it "warns with file when only file is given" do
      expect(@logger).to receive(:send_log).with(:warning, /wet paint.*\(file: aFile\)/m)
      @logger.warn_once('kind', 'wp', "wet paint", 'aFile')
    end

    it "warns with unknown file and line when only line is given" do
      expect(@logger).to receive(:send_log).with(:warning, /wet paint.*\(line: 5\)/m)
      @logger.warn_once('kind', 'wp', "wet paint", nil, 5)
    end

    it "warns with file and line when both are given" do
      expect(@logger).to receive(:send_log).with(:warning, /wet paint.*\(file: aFile, line: 5\)/m)
      @logger.warn_once('kind', 'wp', "wet paint",'aFile', 5)
    end

    it "warns once per key" do
      expect(@logger).to receive(:send_log).with(:warning, /wet paint.*/m).once
      5.times do
        @logger.warn_once('kind', 'wp', "wet paint")
      end
    end

    Puppet::Util::Log.eachlevel do |level|
      it "can use log level #{level}" do
        expect(@logger).to receive(:send_log).with(level, /wet paint.*/m).once
        5.times do
          @logger.warn_once('kind', 'wp', "wet paint", nil, nil, level)
        end
      end
    end
  end

  describe "does not warn about undefined variables when disabled_warnings says so" do
    let(:logger) { LoggingTester.new }

    before(:each) do
      Puppet.settings.initialize_global_settings
      logger.clear_deprecation_warnings
      Puppet[:disable_warnings] = ['undefined_variables']
    end

    after(:each) do
      Puppet[:disable_warnings] = []
      allow(Facter).to receive(:respond_to?).and_call_original()
      allow(Facter).to receive(:debugging).and_call_original()
      allow(logger).to receive(:send_log).and_call_original()
    end

    it "does not produce warning if kind is disabled" do
      expect(logger).not_to receive(:send_log)
      logger.warn_once('undefined_variables', 'wp', "wet paint")
    end
  end

  describe "warns about undefined variables when deprecations are in disabled_warnings" do
    let(:logger) { LoggingTester.new }

    before(:each) do
      Puppet.settings.initialize_global_settings
      logger.clear_deprecation_warnings
      Puppet[:disable_warnings] = ['deprecations']
    end

    after(:each) do
      Puppet[:disable_warnings] = []
      allow(Facter).to receive(:respond_to?).and_call_original()
      allow(Facter).to receive(:debugging).and_call_original()
      allow(logger).to receive(:send_log).and_call_original()
    end

    it "produces warning even if deprecation warnings are disabled " do
      expect(logger).to receive(:send_log).with(:warning, /wet paint/).once
      logger.warn_once('undefined_variables', 'wp', "wet paint")
    end
  end

  describe "when formatting exceptions" do
    it "should be able to format a chain of exceptions" do
      exc3 = Puppet::Error.new("original")
      exc3.set_backtrace(["1.rb:4:in `a'","2.rb:2:in `b'","3.rb:1"])
      exc2 = Puppet::Error.new("second", exc3)
      exc2.set_backtrace(["4.rb:8:in `c'","5.rb:1:in `d'","6.rb:3"])
      exc1 = Puppet::Error.new("third", exc2)
      exc1.set_backtrace(["7.rb:31:in `e'","8.rb:22:in `f'","9.rb:9"])
      # whoa ugly
      expect(@logger.format_exception(exc1)).to match(/third
.*7\.rb:31:in `e'
.*8\.rb:22:in `f'
.*9\.rb:9
Wrapped exception:
second
.*4\.rb:8:in `c'
.*5\.rb:1:in `d'
.*6\.rb:3
Wrapped exception:
original
.*1\.rb:4:in `a'
.*2\.rb:2:in `b'
.*3\.rb:1/)
    end
  end

  describe 'when Facter' do
    after :each do
      # Unstub these calls as there is global code run after
      # each spec that may reset the log level to debug
      allow(Facter).to receive(:respond_to?).and_call_original()
      allow(Facter).to receive(:debugging).and_call_original()
    end

    describe 'does support debugging' do
      before :each do
        allow(Facter).to receive(:respond_to?).with(:debugging).and_return(true)
      end

      it 'enables Facter debugging when debug level' do
        allow(Facter).to receive(:debugging).with(true)
        Puppet::Util::Log.level = :debug
      end

      it 'disables Facter debugging when not debug level' do
        allow(Facter).to receive(:debugging).with(false)
        Puppet::Util::Log.level = :info
      end
    end

    describe 'does support trace' do
      before :each do
        allow(Facter).to receive(:respond_to?).with(:trace).and_return(true)
      end

      it 'enables Facter trace when enabled' do
        allow(Facter).to receive(:trace).with(true)
        Puppet[:trace] = true
      end

      it 'disables Facter trace when disabled' do
        allow(Facter).to receive(:trace).with(false)
        Puppet[:trace] = false
      end
    end

    describe 'does support on_message' do
      before :each do
        allow(Facter).to receive(:respond_to?).with(:on_message).and_return(true)
      end

      def setup(level, message)
        allow(Facter).to receive(:on_message).and_yield(level, message)

        # Transform from Facter level to Puppet level
        case level
        when :trace
          level = :debug
        when :warn
          level = :warning
        when :error
          level = :err
        when :fatal
          level = :crit
        end

        allow(Puppet::Util::Log).to receive(:create).with(hash_including(level: level, message: message, source: 'Facter')).once
      end

      [:trace, :debug, :info, :warn, :error, :fatal].each do |level|
        it "calls Facter.on_message and handles #{level} messages" do
          setup(level, "#{level} message")
          expect(Puppet::Util::Logging::setup_facter_logging!).to be_truthy
        end
      end
    end
  end
end