aboutsummaryrefslogtreecommitdiffstats
path: root/activesupport/test/buffered_logger_test.rb
blob: 8d1b1c02c6d90a0e1d691c2422ad8f196e2cc04c (plain) (blame)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
require 'abstract_unit'
require 'multibyte_test_helpers'
require 'stringio'
require 'fileutils'
require 'active_support/buffered_logger'

class BufferedLoggerTest < Test::Unit::TestCase
  include MultibyteTestHelpers

  Logger = ActiveSupport::BufferedLogger

  def setup
    @message = "A debug message"
    @integer_message = 12345
    @output  = StringIO.new
    @logger  = Logger.new(@output)
  end

  def test_should_log_debugging_message_when_debugging
    @logger.level = Logger::DEBUG
    @logger.add(Logger::DEBUG, @message)
    assert @output.string.include?(@message)
  end

  def test_should_not_log_debug_messages_when_log_level_is_info
    @logger.level = Logger::INFO
    @logger.add(Logger::DEBUG, @message)
    assert ! @output.string.include?(@message)
  end

  def test_should_add_message_passed_as_block_when_using_add
    @logger.level = Logger::INFO
    @logger.add(Logger::INFO) {@message}
    assert @output.string.include?(@message)
  end

  def test_should_add_message_passed_as_block_when_using_shortcut
    @logger.level = Logger::INFO
    @logger.info {@message}
    assert @output.string.include?(@message)
  end

  def test_should_convert_message_to_string
    @logger.level = Logger::INFO
    @logger.info @integer_message
    assert @output.string.include?(@integer_message.to_s)
  end

  def test_should_convert_message_to_string_when_passed_in_block
    @logger.level = Logger::INFO
    @logger.info {@integer_message}
    assert @output.string.include?(@integer_message.to_s)
  end

  def test_should_not_evaluate_block_if_message_wont_be_logged
    @logger.level = Logger::INFO
    evaluated = false
    @logger.add(Logger::DEBUG) {evaluated = true}
    assert evaluated == false
  end

  def test_should_not_mutate_message
    message_copy = @message.dup
    @logger.info @message
    assert_equal message_copy, @message
  end


  [false, nil, 0].each do |disable|
    define_method "test_disabling_auto_flush_with_#{disable.inspect}_should_buffer_until_explicit_flush" do
      @logger.auto_flushing = disable

      4.times do
        @logger.info 'wait for it..'
        assert @output.string.empty?, "@output.string should be empty but it is #{@output.string}"
      end

      @logger.flush
      assert !@output.string.empty?, "@logger.send(:buffer).size.to_s should not be empty but it is empty"
    end

    define_method "test_disabling_auto_flush_with_#{disable.inspect}_should_flush_at_max_buffer_size_as_failsafe" do
      @logger.auto_flushing = disable
      assert_equal Logger::MAX_BUFFER_SIZE, @logger.auto_flushing

      (Logger::MAX_BUFFER_SIZE - 1).times do
        @logger.info 'wait for it..'
        assert @output.string.empty?, "@output.string should be empty but is #{@output.string}"
      end

      @logger.info 'there it is.'
      assert !@output.string.empty?, "@logger.send(:buffer).size.to_s should not be empty but it is empty"
    end
  end

  def test_should_know_if_its_loglevel_is_below_a_given_level
    Logger::Severity.constants.each do |level|
      @logger.level = Logger::Severity.const_get(level) - 1
      assert @logger.send("#{level.downcase}?"), "didn't know if it was #{level.downcase}? or below"
    end
  end

  def test_should_auto_flush_every_n_messages
    @logger.auto_flushing = 5

    4.times do
      @logger.info 'wait for it..'
      assert @output.string.empty?, "@output.string should be empty but it is #{@output.string}"
    end

    @logger.info 'there it is.'
    assert !@output.string.empty?, "@output.string should not be empty but it is empty"
  end

  def test_should_create_the_log_directory_if_it_doesnt_exist
    tmp_directory = File.join(File.dirname(__FILE__), "tmp")
    log_file = File.join(tmp_directory, "development.log")
    FileUtils.rm_rf(tmp_directory)
    @logger  = Logger.new(log_file)
    assert File.exist?(tmp_directory)
  end

  def test_logger_should_maintain_separate_buffers_for_each_thread
    @logger.auto_flushing = false

    a = Thread.new do
      @logger.info("a"); Thread.pass;
      @logger.info("b"); Thread.pass;
      @logger.info("c"); @logger.flush
    end

    b = Thread.new do
      @logger.info("x"); Thread.pass;
      @logger.info("y"); Thread.pass;
      @logger.info("z"); @logger.flush
    end

    a.join
    b.join

    assert @output.string.include?("a\nb\nc\n")
    assert @output.string.include?("x\ny\nz\n")
  end

  def test_flush_should_remove_empty_buffers
    @logger.send :buffer
    @logger.expects :clear_buffer
    @logger.flush
  end

  def test_buffer_multibyte
    @logger.auto_flushing = 2
    @logger.info(UNICODE_STRING)
    @logger.info(BYTE_STRING)
    assert @output.string.include?(UNICODE_STRING)
    byte_string = @output.string.dup
    if byte_string.respond_to?(:force_encoding)
      byte_string.force_encoding("ASCII-8BIT")
    end
    assert byte_string.include?(BYTE_STRING)
  end
end