2010-02-15 09:44:30 -05:00
|
|
|
require 'abstract_unit'
|
2010-06-24 07:23:43 -04:00
|
|
|
require 'active_support/log_subscriber/test_helper'
|
2010-02-15 09:44:30 -05:00
|
|
|
|
2010-06-24 07:23:43 -04:00
|
|
|
class MyLogSubscriber < ActiveSupport::LogSubscriber
|
2010-02-15 09:44:30 -05:00
|
|
|
attr_reader :event
|
|
|
|
|
|
|
|
def some_event(event)
|
|
|
|
@event = event
|
|
|
|
info event.name
|
|
|
|
end
|
|
|
|
|
|
|
|
def foo(event)
|
|
|
|
debug "debug"
|
2012-05-17 02:52:40 -04:00
|
|
|
info { "info" }
|
2010-02-15 09:44:30 -05:00
|
|
|
warn "warn"
|
|
|
|
end
|
|
|
|
|
|
|
|
def bar(event)
|
|
|
|
info "#{color("cool", :red)}, #{color("isn't it?", :blue, true)}"
|
|
|
|
end
|
|
|
|
|
|
|
|
def puke(event)
|
|
|
|
raise "puke"
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
class SyncLogSubscriberTest < ActiveSupport::TestCase
|
2010-06-24 07:23:43 -04:00
|
|
|
include ActiveSupport::LogSubscriber::TestHelper
|
2010-02-15 09:44:30 -05:00
|
|
|
|
|
|
|
def setup
|
|
|
|
super
|
|
|
|
@log_subscriber = MyLogSubscriber.new
|
|
|
|
end
|
|
|
|
|
|
|
|
def teardown
|
|
|
|
super
|
2010-06-24 07:23:43 -04:00
|
|
|
ActiveSupport::LogSubscriber.log_subscribers.clear
|
2010-02-15 09:44:30 -05:00
|
|
|
end
|
|
|
|
|
|
|
|
def instrument(*args, &block)
|
|
|
|
ActiveSupport::Notifications.instrument(*args, &block)
|
|
|
|
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
|
2010-06-24 07:23:43 -04:00
|
|
|
ActiveSupport::LogSubscriber.colorize_logging = true
|
2010-02-15 09:44:30 -05:00
|
|
|
@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_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
|
2010-06-24 07:23:43 -04:00
|
|
|
ActiveSupport::LogSubscriber.attach_to :my_log_subscriber, @log_subscriber
|
2010-04-28 00:16:06 -04:00
|
|
|
instrument "some_event.my_log_subscriber"
|
2010-02-15 09:44:30 -05:00
|
|
|
wait
|
2010-04-28 00:16:06 -04:00
|
|
|
assert_equal %w(some_event.my_log_subscriber), @logger.logged(:info)
|
2010-02-15 09:44:30 -05:00
|
|
|
end
|
|
|
|
|
|
|
|
def test_event_is_an_active_support_notifications_event
|
2010-06-24 07:23:43 -04:00
|
|
|
ActiveSupport::LogSubscriber.attach_to :my_log_subscriber, @log_subscriber
|
2010-04-28 00:16:06 -04:00
|
|
|
instrument "some_event.my_log_subscriber"
|
2010-02-15 09:44:30 -05:00
|
|
|
wait
|
|
|
|
assert_kind_of ActiveSupport::Notifications::Event, @log_subscriber.event
|
|
|
|
end
|
|
|
|
|
|
|
|
def test_does_not_send_the_event_if_it_doesnt_match_the_class
|
2010-06-24 07:23:43 -04:00
|
|
|
ActiveSupport::LogSubscriber.attach_to :my_log_subscriber, @log_subscriber
|
2010-04-28 00:16:06 -04:00
|
|
|
instrument "unknown_event.my_log_subscriber"
|
2010-02-15 09:44:30 -05:00
|
|
|
wait
|
2010-02-16 15:37:30 -05:00
|
|
|
# If we get here, it means that NoMethodError was not raised.
|
2010-02-15 09:44:30 -05:00
|
|
|
end
|
|
|
|
|
|
|
|
def test_does_not_send_the_event_if_logger_is_nil
|
2010-06-24 07:23:43 -04:00
|
|
|
ActiveSupport::LogSubscriber.logger = nil
|
2010-02-15 09:44:30 -05:00
|
|
|
@log_subscriber.expects(:some_event).never
|
2010-06-24 07:23:43 -04:00
|
|
|
ActiveSupport::LogSubscriber.attach_to :my_log_subscriber, @log_subscriber
|
2010-04-28 00:16:06 -04:00
|
|
|
instrument "some_event.my_log_subscriber"
|
2010-02-15 09:44:30 -05:00
|
|
|
wait
|
|
|
|
end
|
|
|
|
|
2010-02-16 15:37:30 -05:00
|
|
|
def test_does_not_fail_with_non_namespaced_events
|
2010-06-24 07:23:43 -04:00
|
|
|
ActiveSupport::LogSubscriber.attach_to :my_log_subscriber, @log_subscriber
|
2010-02-16 15:37:30 -05:00
|
|
|
instrument "whatever"
|
|
|
|
wait
|
|
|
|
end
|
|
|
|
|
2010-02-15 09:44:30 -05:00
|
|
|
def test_flushes_loggers
|
2010-06-24 07:23:43 -04:00
|
|
|
ActiveSupport::LogSubscriber.attach_to :my_log_subscriber, @log_subscriber
|
|
|
|
ActiveSupport::LogSubscriber.flush_all!
|
2010-02-15 09:44:30 -05:00
|
|
|
assert_equal 1, @logger.flush_count
|
|
|
|
end
|
|
|
|
|
|
|
|
def test_flushes_the_same_logger_just_once
|
2010-06-24 07:23:43 -04:00
|
|
|
ActiveSupport::LogSubscriber.attach_to :my_log_subscriber, @log_subscriber
|
|
|
|
ActiveSupport::LogSubscriber.attach_to :another, @log_subscriber
|
|
|
|
ActiveSupport::LogSubscriber.flush_all!
|
2010-02-15 09:44:30 -05:00
|
|
|
wait
|
|
|
|
assert_equal 1, @logger.flush_count
|
|
|
|
end
|
|
|
|
|
|
|
|
def test_logging_does_not_die_on_failures
|
2010-06-24 07:23:43 -04:00
|
|
|
ActiveSupport::LogSubscriber.attach_to :my_log_subscriber, @log_subscriber
|
2010-04-28 00:16:06 -04:00
|
|
|
instrument "puke.my_log_subscriber"
|
|
|
|
instrument "some_event.my_log_subscriber"
|
2010-02-15 09:44:30 -05:00
|
|
|
wait
|
|
|
|
|
|
|
|
assert_equal 1, @logger.logged(:info).size
|
2010-04-28 00:16:06 -04:00
|
|
|
assert_equal 'some_event.my_log_subscriber', @logger.logged(:info).last
|
2010-02-15 09:44:30 -05:00
|
|
|
|
|
|
|
assert_equal 1, @logger.logged(:error).size
|
2012-01-20 14:53:47 -05:00
|
|
|
assert_match 'Could not log "puke.my_log_subscriber" event. RuntimeError: puke', @logger.logged(:error).last
|
2010-02-15 09:44:30 -05:00
|
|
|
end
|
2012-01-20 14:53:47 -05:00
|
|
|
end
|