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
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
|
# frozen_string_literal: true
require_relative "abstract_unit"
require "active_support/log_subscriber/test_helper"
class SyncLogSubscriberTest < ActiveSupport::TestCase
include ActiveSupport::LogSubscriber::TestHelper
class MyLogSubscriber < ActiveSupport::LogSubscriber
attr_reader :event
def some_event(event)
@event = event
info event.name
end
def foo(event)
debug "debug"
info { "info" }
warn "warn"
end
def bar(event)
info "#{color("cool", :red)}, #{color("isn't it?", :blue, bold: true)}"
end
def baz(event)
info "#{color("rad", :green, bold: true, underline: true)}, #{color("isn't it?", :yellow, italic: true)}"
end
def puke(event)
raise "puke"
end
def debug_only(event)
debug "debug logs are enabled"
end
subscribe_log_level :debug_only, :debug
end
def setup
super
@log_subscriber = MyLogSubscriber.new
end
def teardown
super
ActiveSupport::LogSubscriber.log_subscribers.clear
end
def test_proxies_method_to_rails_logger
@log_subscriber.foo(nil)
assert_equal %w(debug), @logger.logged(:debug)
assert_equal %w(info), @logger.logged(:info)
assert_equal %w(warn), @logger.logged(:warn)
end
def test_set_color_for_messages
ActiveSupport::LogSubscriber.colorize_logging = true
@log_subscriber.bar(nil)
assert_equal "\e[31mcool\e[0m, \e[1m\e[34misn't it?\e[0m", @logger.logged(:info).last
end
def test_set_mode_for_messages
ActiveSupport::LogSubscriber.colorize_logging = true
@log_subscriber.baz(nil)
assert_equal "\e[1;4m\e[32mrad\e[0m, \e[3m\e[33misn't it?\e[0m", @logger.logged(:info).last
end
def test_does_not_set_color_if_colorize_logging_is_set_to_false
@log_subscriber.bar(nil)
assert_equal "cool, isn't it?", @logger.logged(:info).last
end
def test_event_is_sent_to_the_registered_class
ActiveSupport::LogSubscriber.attach_to :my_log_subscriber, @log_subscriber
instrument "some_event.my_log_subscriber"
wait
assert_equal %w(some_event.my_log_subscriber), @logger.logged(:info)
end
def test_event_is_an_active_support_notifications_event
ActiveSupport::LogSubscriber.attach_to :my_log_subscriber, @log_subscriber
instrument "some_event.my_log_subscriber"
wait
assert_kind_of ActiveSupport::Notifications::Event, @log_subscriber.event
end
def test_event_attributes
ActiveSupport::LogSubscriber.attach_to :my_log_subscriber, @log_subscriber
instrument "some_event.my_log_subscriber" do
[] # Make an allocation
end
wait
event = @log_subscriber.event
if defined?(JRUBY_VERSION)
assert_equal 0, event.cpu_time
assert_equal 0, event.allocations
else
assert_operator event.cpu_time, :>, 0
assert_operator event.allocations, :>, 0
end
assert_operator event.duration, :>, 0
assert_operator event.idle_time, :>=, 0
end
def test_does_not_send_the_event_if_it_doesnt_match_the_class
assert_nothing_raised do
ActiveSupport::LogSubscriber.attach_to :my_log_subscriber, @log_subscriber
instrument "unknown_event.my_log_subscriber"
wait
end
end
def test_does_not_send_the_event_if_logger_is_nil
ActiveSupport::LogSubscriber.logger = nil
assert_not_called(@log_subscriber, :some_event) do
ActiveSupport::LogSubscriber.attach_to :my_log_subscriber, @log_subscriber
instrument "some_event.my_log_subscriber"
wait
end
end
def test_does_not_fail_with_non_namespaced_events
assert_nothing_raised do
ActiveSupport::LogSubscriber.attach_to :my_log_subscriber, @log_subscriber
instrument "whatever"
wait
end
end
def test_flushes_loggers
ActiveSupport::LogSubscriber.attach_to :my_log_subscriber, @log_subscriber
ActiveSupport::LogSubscriber.flush_all!
assert_equal 1, @logger.flush_count
end
def test_flushes_the_same_logger_just_once
ActiveSupport::LogSubscriber.attach_to :my_log_subscriber, @log_subscriber
ActiveSupport::LogSubscriber.attach_to :another, @log_subscriber
ActiveSupport::LogSubscriber.flush_all!
wait
assert_equal 1, @logger.flush_count
end
def test_logging_does_not_die_on_failures
ActiveSupport::LogSubscriber.attach_to :my_log_subscriber, @log_subscriber
instrument "puke.my_log_subscriber"
instrument "some_event.my_log_subscriber"
wait
assert_equal 1, @logger.logged(:info).size
assert_equal "some_event.my_log_subscriber", @logger.logged(:info).last
assert_equal 1, @logger.logged(:error).size
assert_match 'Could not log "puke.my_log_subscriber" event. RuntimeError: puke', @logger.logged(:error).last
end
def test_subscribe_log_level
MyLogSubscriber.logger = @logger
@logger.level = Logger::INFO
MyLogSubscriber.attach_to :my_log_subscriber, @log_subscriber
assert_empty @logger.logged(:debug)
instrument "debug_only.my_log_subscriber"
wait
assert_empty @logger.logged(:debug)
@logger.level = Logger::DEBUG
instrument "debug_only.my_log_subscriber"
wait
assert_not_empty @logger.logged(:debug)
end
class MockSemanticLogger < MockLogger
LEVELS = [:debug, :info]
def level
LEVELS[super]
end
end
def test_subscribe_log_level_with_non_numeric_levels
# The semantic_logger gem doesn't returns integers but symbols as levels
@logger = MockSemanticLogger.new
set_logger(@logger)
MyLogSubscriber.logger = @logger
@logger.level = Logger::INFO
MyLogSubscriber.attach_to :my_log_subscriber, @log_subscriber
assert_empty @logger.logged(:debug)
instrument "debug_only.my_log_subscriber"
wait
assert_empty @logger.logged(:debug)
@logger.level = Logger::DEBUG
instrument "debug_only.my_log_subscriber"
wait
assert_not_empty @logger.logged(:debug)
end
private
def instrument(*args, &block)
ActiveSupport::Notifications.instrument(*args, &block)
end
end
|
