require "spec_helper"

describe Lumber::JsonFormatter do

  context "log4r yaml configuration" do

    it "has default values without configuration" do
      yml = <<-EOF
        log4r_config:
          pre_config:
            root:
              level: 'DEBUG'
          loggers:
            - name: "mylogger"

          outputters:
            - type: StdoutOutputter
              name: stdout
              formatter:
                type: JsonFormatter
      EOF

      cfg = Log4r::YamlConfigurator
      cfg.load_yaml_string(yml)
      outputter = Log4r::Outputter['stdout']
      outputter.formatter.should_not be_nil
      outputter.formatter.should be_a_kind_of Lumber::JsonFormatter
    end

    it "can receive configuration" do
      yml = <<-EOF
        log4r_config:
          pre_config:
            root:
              level: 'DEBUG'
          loggers:
            - name: "mylogger"

          outputters:
            - type: StdoutOutputter
              name: stdout
              formatter:
                type: JsonFormatter
                key_mapping:
                  level: severity
                  backtrace: exception.bt
      EOF

      cfg = Log4r::YamlConfigurator
      cfg.load_yaml_string(yml)
      outputter = Log4r::Outputter['stdout']
      outputter.formatter.should_not be_nil
      outputter.formatter.should be_a_kind_of Lumber::JsonFormatter
      outputter.formatter.instance_variable_get(:@key_mapping).should eq({'level' => ['severity'], 'backtrace' => ['exception', 'bt']})
    end

  end
  
  context "#assign_mapped_key" do
    
    it "handles no mapping" do
      formatter = Lumber::JsonFormatter.new()
      data = {}
      formatter.send(:assign_mapped_key, data, 'foo', 'bar')
      data['foo'].should == 'bar'
    end
    
    it "handles simple mapping" do
      formatter = Lumber::JsonFormatter.new('key_mapping' => {'foo' => 'baz'})
      data = {}
      formatter.send(:assign_mapped_key, data, 'foo', 'bar')
      data['foo'].should be_nil
      data['baz'].should == 'bar'
    end

    it "handles deep mapping" do
      formatter = Lumber::JsonFormatter.new('key_mapping' => {'foo' => 'baz.bum'})
      data = {}
      formatter.send(:assign_mapped_key, data, 'foo', 'bar')
      data['foo'].should be_nil
      data['baz'].should eq({'bum' => 'bar'})
    end

    it "handles overlapping deep mapping" do
      formatter = Lumber::JsonFormatter.new('key_mapping' => {'foo' => 'baz.bum', 'dum' => 'baz.derf'})
      data = {}
      formatter.send(:assign_mapped_key, data, 'foo', 'bar')
      formatter.send(:assign_mapped_key, data, 'dum', 'hum')
      data['foo'].should be_nil
      data['dum'].should be_nil
      data['baz'].should eq({'bum' => 'bar', 'derf' => 'hum'})
    end

  end
  
  context "log contents" do

    before(:each) do
      @logger = Lumber.find_or_create_logger('mylogger')
      @sio = StringIO.new
      @outputter = Log4r::IOOutputter.new("sbout", @sio)
      @formatter = Lumber::JsonFormatter.new
      @outputter.formatter = @formatter
      @logger.outputters.clear
      @logger.outputters << @outputter

      Log4r::GDC.set(nil)
      Log4r::NDC.clear
      Log4r::MDC.get_context.keys.each {|k| Log4r::MDC.remove(k) }
    end
    
    it "logs as json" do
      @logger.info("howdy")
      @sio.string.size.should be_present
      json = JSON.parse(@sio.string)
      json['logger'].should == 'mylogger'
      json['level'].should == 'info'
      json['message'].should == 'howdy'
      json['timestamp'].should be_present
    end
    
    it "logs as json with mapping" do
      @formatter = Lumber::JsonFormatter.new('key_mapping' => {'level' => 'severity'})
      @outputter.formatter = @formatter

      @logger.info("howdy")
      json = JSON.parse(@sio.string)
      json['level'].should be_nil
      json['severity'].should == 'info'
    end

    it "logs exception as json" do
      ex = StandardError.new("mybad")
      raise ex rescue nil
      @logger.error(ex)
      json = JSON.parse(@sio.string)
      json['message'].should == 'Caught StandardError: mybad'
      json['level'].should == 'error'
      json['backtrace'].should =~  /json_formatter_spec.rb:\d+/
      json['file'].should =~ /^\/.*json_formatter_spec.rb$/
      json['line'].should > 0
    end
    
    it "doesn't set file/line/method by default" do
      @logger.fatal("no tracing")
      json = JSON.parse(@sio.string)
      json['file'].should be_nil
      json['line'].should be_nil
      json['method'].should be_nil
    end

    it "uses trace data if enabled" do
      @logger.trace = true
      @logger.fatal("no tracing")
      json = JSON.parse(@sio.string)
      json['file'].should =~ /^\/.*json_formatter_spec.rb$/
      json['line'].should > 0
      json['method'].should be_present
    end
    
    it "uses global log4r context if available" do
      Log4r::GDC.set("mygdc")
      @logger.info("context")
      json = JSON.parse(@sio.string)
      json['gdc'].should == '"mygdc"'
    end
    
    it "uses nested log4r context if available" do
      Log4r::NDC.push("myndc0")
      Log4r::NDC.push(99)
      @logger.info("context")
      json = JSON.parse(@sio.string)
      json['ndc'].should == ['"myndc0"', "99"]
    end
    
    it "uses mapped log4r context if available" do
      Log4r::MDC.put("foo", "mymdcfoo")
      Log4r::MDC.put("lucky", 7)
      Log4r::MDC.put("myclass", Object)
      @logger.info("context")
      json = JSON.parse(@sio.string)
      json['mdc'].should == {"foo" => '"mymdcfoo"', "lucky" => "7", "myclass" => "Object"}
    end

    it "handles failure inspecting log4r context" do
      o = Object.new
      o.stub(:inspect).and_raise("bad")
      Log4r::GDC.set(o)
      Log4r::NDC.push(o); Log4r::NDC.push(5)
      Log4r::MDC.put("obj", o); Log4r::MDC.put("foo", "bar")
      @logger.info("context")
      json = JSON.parse(@sio.string)
      json['gdc'].should be_nil
      json['ndc'].should == ["5"]
      json['mdc'].should == {"foo" => '"bar"'}
    end
  end

end