From f0523f72b46db14e2f50c8347a8708734c650f84 Mon Sep 17 00:00:00 2001 From: Prem Sichanugrist Date: Mon, 15 Feb 2010 21:44:30 +0700 Subject: Rename Rails::Subscriber to Rails::LogSubscriber --- actionmailer/lib/action_mailer/railtie.rb | 4 +- .../lib/action_mailer/railties/log_subscriber.rb | 20 +++ .../lib/action_mailer/railties/subscriber.rb | 20 --- actionmailer/test/log_subscriber_test.rb | 44 ++++++ actionmailer/test/subscriber_test.rb | 44 ------ actionpack/lib/action_controller/railtie.rb | 4 +- .../action_controller/railties/log_subscriber.rb | 62 ++++++++ .../lib/action_controller/railties/subscriber.rb | 62 -------- actionpack/lib/action_view/railtie.rb | 4 +- .../lib/action_view/railties/log_subscriber.rb | 24 +++ actionpack/lib/action_view/railties/subscriber.rb | 24 --- .../test/activerecord/controller_runtime_test.rb | 16 +- actionpack/test/controller/log_subscriber_test.rb | 172 +++++++++++++++++++++ actionpack/test/controller/subscriber_test.rb | 172 --------------------- actionpack/test/template/log_subscriber_test.rb | 93 +++++++++++ actionpack/test/template/subscriber_test.rb | 93 ----------- activerecord/lib/active_record/base.rb | 2 +- activerecord/lib/active_record/railtie.rb | 4 +- .../lib/active_record/railties/log_subscriber.rb | 27 ++++ .../lib/active_record/railties/subscriber.rb | 27 ---- activerecord/test/cases/log_subscriber_test.rb | 42 +++++ activerecord/test/cases/subscriber_test.rb | 42 ----- activeresource/lib/active_resource/railtie.rb | 4 +- .../lib/active_resource/railties/log_subscriber.rb | 15 ++ .../lib/active_resource/railties/subscriber.rb | 15 -- activeresource/test/cases/log_subscriber_test.rb | 31 ++++ activeresource/test/cases/subscriber_test.rb | 31 ---- activesupport/lib/active_support/notifications.rb | 4 +- .../lib/active_support/notifications/fanout.rb | 10 +- activesupport/test/notifications_test.rb | 6 +- railties/guides/source/3_0_release_notes.textile | 2 +- railties/lib/rails.rb | 2 +- railties/lib/rails/application/bootstrap.rb | 8 +- railties/lib/rails/log_subscriber.rb | 108 +++++++++++++ railties/lib/rails/log_subscriber/test_helper.rb | 98 ++++++++++++ railties/lib/rails/rack/logger.rb | 6 +- railties/lib/rails/railtie.rb | 4 +- railties/lib/rails/subscriber.rb | 108 ------------- railties/lib/rails/subscriber/test_helper.rb | 98 ------------ .../application/initializers/notifications_test.rb | 2 +- railties/test/log_subscriber_test.rb | 119 ++++++++++++++ railties/test/railties/railtie_test.rb | 8 +- railties/test/subscriber_test.rb | 119 -------------- 43 files changed, 900 insertions(+), 900 deletions(-) create mode 100644 actionmailer/lib/action_mailer/railties/log_subscriber.rb delete mode 100644 actionmailer/lib/action_mailer/railties/subscriber.rb create mode 100644 actionmailer/test/log_subscriber_test.rb delete mode 100644 actionmailer/test/subscriber_test.rb create mode 100644 actionpack/lib/action_controller/railties/log_subscriber.rb delete mode 100644 actionpack/lib/action_controller/railties/subscriber.rb create mode 100644 actionpack/lib/action_view/railties/log_subscriber.rb delete mode 100644 actionpack/lib/action_view/railties/subscriber.rb create mode 100644 actionpack/test/controller/log_subscriber_test.rb delete mode 100644 actionpack/test/controller/subscriber_test.rb create mode 100644 actionpack/test/template/log_subscriber_test.rb delete mode 100644 actionpack/test/template/subscriber_test.rb create mode 100644 activerecord/lib/active_record/railties/log_subscriber.rb delete mode 100644 activerecord/lib/active_record/railties/subscriber.rb create mode 100644 activerecord/test/cases/log_subscriber_test.rb delete mode 100644 activerecord/test/cases/subscriber_test.rb create mode 100644 activeresource/lib/active_resource/railties/log_subscriber.rb delete mode 100644 activeresource/lib/active_resource/railties/subscriber.rb create mode 100644 activeresource/test/cases/log_subscriber_test.rb delete mode 100644 activeresource/test/cases/subscriber_test.rb create mode 100644 railties/lib/rails/log_subscriber.rb create mode 100644 railties/lib/rails/log_subscriber/test_helper.rb delete mode 100644 railties/lib/rails/subscriber.rb delete mode 100644 railties/lib/rails/subscriber/test_helper.rb create mode 100644 railties/test/log_subscriber_test.rb delete mode 100644 railties/test/subscriber_test.rb diff --git a/actionmailer/lib/action_mailer/railtie.rb b/actionmailer/lib/action_mailer/railtie.rb index a3afc23e6a..4c48d2bed6 100644 --- a/actionmailer/lib/action_mailer/railtie.rb +++ b/actionmailer/lib/action_mailer/railtie.rb @@ -9,8 +9,8 @@ module ActionMailer ActionMailer::Base.send(:include, ActionController::UrlFor) if defined?(ActionController) end - require "action_mailer/railties/subscriber" - subscriber ActionMailer::Railties::Subscriber.new + require "action_mailer/railties/log_subscriber" + log_subscriber ActionMailer::Railties::LogSubscriber.new initializer "action_mailer.logger" do ActionMailer::Base.logger ||= Rails.logger diff --git a/actionmailer/lib/action_mailer/railties/log_subscriber.rb b/actionmailer/lib/action_mailer/railties/log_subscriber.rb new file mode 100644 index 0000000000..d1b3dd33af --- /dev/null +++ b/actionmailer/lib/action_mailer/railties/log_subscriber.rb @@ -0,0 +1,20 @@ +module ActionMailer + module Railties + class LogSubscriber < Rails::LogSubscriber + def deliver(event) + recipients = Array(event.payload[:to]).join(', ') + info("\nSent mail to #{recipients} (%1.fms)" % event.duration) + debug(event.payload[:mail]) + end + + def receive(event) + info("\nReceived mail (%.1fms)" % event.duration) + debug(event.payload[:mail]) + end + + def logger + ActionMailer::Base.logger + end + end + end +end \ No newline at end of file diff --git a/actionmailer/lib/action_mailer/railties/subscriber.rb b/actionmailer/lib/action_mailer/railties/subscriber.rb deleted file mode 100644 index cff852055c..0000000000 --- a/actionmailer/lib/action_mailer/railties/subscriber.rb +++ /dev/null @@ -1,20 +0,0 @@ -module ActionMailer - module Railties - class Subscriber < Rails::Subscriber - def deliver(event) - recipients = Array(event.payload[:to]).join(', ') - info("\nSent mail to #{recipients} (%1.fms)" % event.duration) - debug(event.payload[:mail]) - end - - def receive(event) - info("\nReceived mail (%.1fms)" % event.duration) - debug(event.payload[:mail]) - end - - def logger - ActionMailer::Base.logger - end - end - end -end \ No newline at end of file diff --git a/actionmailer/test/log_subscriber_test.rb b/actionmailer/test/log_subscriber_test.rb new file mode 100644 index 0000000000..edd7c84d29 --- /dev/null +++ b/actionmailer/test/log_subscriber_test.rb @@ -0,0 +1,44 @@ +require "abstract_unit" +require "rails/log_subscriber/test_helper" +require "action_mailer/railties/log_subscriber" + +class AMLogSubscriberTest < ActionMailer::TestCase + include Rails::LogSubscriber::TestHelper + Rails::LogSubscriber.add(:action_mailer, ActionMailer::Railties::LogSubscriber.new) + + class TestMailer < ActionMailer::Base + def basic + recipients "somewhere@example.com" + subject "basic" + from "basic@example.com" + body "Hello world" + end + + def receive(mail) + # Do nothing + end + end + + def set_logger(logger) + ActionMailer::Base.logger = logger + end + + def test_deliver_is_notified + TestMailer.basic.deliver + wait + assert_equal(1, @logger.logged(:info).size) + assert_match(/Sent mail to somewhere@example.com/, @logger.logged(:info).first) + assert_equal(1, @logger.logged(:debug).size) + assert_match(/Hello world/, @logger.logged(:debug).first) + end + + def test_receive_is_notified + fixture = File.read(File.dirname(__FILE__) + "/fixtures/raw_email") + TestMailer.receive(fixture) + wait + assert_equal(1, @logger.logged(:info).size) + assert_match(/Received mail/, @logger.logged(:info).first) + assert_equal(1, @logger.logged(:debug).size) + assert_match(/Jamis/, @logger.logged(:debug).first) + end +end \ No newline at end of file diff --git a/actionmailer/test/subscriber_test.rb b/actionmailer/test/subscriber_test.rb deleted file mode 100644 index 3d1736d64f..0000000000 --- a/actionmailer/test/subscriber_test.rb +++ /dev/null @@ -1,44 +0,0 @@ -require "abstract_unit" -require "rails/subscriber/test_helper" -require "action_mailer/railties/subscriber" - -class AMSubscriberTest < ActionMailer::TestCase - include Rails::Subscriber::TestHelper - Rails::Subscriber.add(:action_mailer, ActionMailer::Railties::Subscriber.new) - - class TestMailer < ActionMailer::Base - def basic - recipients "somewhere@example.com" - subject "basic" - from "basic@example.com" - body "Hello world" - end - - def receive(mail) - # Do nothing - end - end - - def set_logger(logger) - ActionMailer::Base.logger = logger - end - - def test_deliver_is_notified - TestMailer.basic.deliver - wait - assert_equal(1, @logger.logged(:info).size) - assert_match(/Sent mail to somewhere@example.com/, @logger.logged(:info).first) - assert_equal(1, @logger.logged(:debug).size) - assert_match(/Hello world/, @logger.logged(:debug).first) - end - - def test_receive_is_notified - fixture = File.read(File.dirname(__FILE__) + "/fixtures/raw_email") - TestMailer.receive(fixture) - wait - assert_equal(1, @logger.logged(:info).size) - assert_match(/Received mail/, @logger.logged(:info).first) - assert_equal(1, @logger.logged(:debug).size) - assert_match(/Jamis/, @logger.logged(:debug).first) - end -end \ No newline at end of file diff --git a/actionpack/lib/action_controller/railtie.rb b/actionpack/lib/action_controller/railtie.rb index 55a5c22ac0..015a8212c4 100644 --- a/actionpack/lib/action_controller/railtie.rb +++ b/actionpack/lib/action_controller/railtie.rb @@ -6,8 +6,8 @@ module ActionController class Railtie < Rails::Railtie railtie_name :action_controller - require "action_controller/railties/subscriber" - subscriber ActionController::Railties::Subscriber.new + require "action_controller/railties/log_subscriber" + log_subscriber ActionController::Railties::LogSubscriber.new initializer "action_controller.logger" do ActionController::Base.logger ||= Rails.logger diff --git a/actionpack/lib/action_controller/railties/log_subscriber.rb b/actionpack/lib/action_controller/railties/log_subscriber.rb new file mode 100644 index 0000000000..df9ffa1717 --- /dev/null +++ b/actionpack/lib/action_controller/railties/log_subscriber.rb @@ -0,0 +1,62 @@ +module ActionController + module Railties + class LogSubscriber < Rails::LogSubscriber + INTERNAL_PARAMS = %w(controller action format _method only_path) + + def start_processing(event) + payload = event.payload + params = payload[:params].except(*INTERNAL_PARAMS) + + info " Processing by #{payload[:controller]}##{payload[:action]} as #{payload[:formats].first.to_s.upcase}" + info " Parameters: #{params.inspect}" unless params.empty? + end + + def process_action(event) + payload = event.payload + additions = ActionController::Base.log_process_action(payload) + + message = "Completed #{payload[:status]} #{Rack::Utils::HTTP_STATUS_CODES[payload[:status]]} in %.0fms" % event.duration + message << " (#{additions.join(" | ")})" unless additions.blank? + + info(message) + end + + def send_file(event) + message = if event.payload[:x_sendfile] + header = ActionController::Streaming::X_SENDFILE_HEADER + "Sent #{header} header %s" + elsif event.payload[:stream] + "Streamed file %s" + else + "Sent file %s" + end + + message << " (%.1fms)" + info(message % [event.payload[:path], event.duration]) + end + + def redirect_to(event) + info "Redirected to #{event.payload[:location]}" + end + + def send_data(event) + info("Sent data %s (%.1fms)" % [event.payload[:filename], event.duration]) + end + + %w(write_fragment read_fragment exist_fragment? + expire_fragment expire_page write_page).each do |method| + class_eval <<-METHOD, __FILE__, __LINE__ + 1 + def #{method}(event) + key_or_path = event.payload[:key] || event.payload[:path] + human_name = #{method.to_s.humanize.inspect} + info("\#{human_name} \#{key_or_path} (%.1fms)" % event.duration) + end + METHOD + end + + def logger + ActionController::Base.logger + end + end + end +end \ No newline at end of file diff --git a/actionpack/lib/action_controller/railties/subscriber.rb b/actionpack/lib/action_controller/railties/subscriber.rb deleted file mode 100644 index 4499e82292..0000000000 --- a/actionpack/lib/action_controller/railties/subscriber.rb +++ /dev/null @@ -1,62 +0,0 @@ -module ActionController - module Railties - class Subscriber < Rails::Subscriber - INTERNAL_PARAMS = %w(controller action format _method only_path) - - def start_processing(event) - payload = event.payload - params = payload[:params].except(*INTERNAL_PARAMS) - - info " Processing by #{payload[:controller]}##{payload[:action]} as #{payload[:formats].first.to_s.upcase}" - info " Parameters: #{params.inspect}" unless params.empty? - end - - def process_action(event) - payload = event.payload - additions = ActionController::Base.log_process_action(payload) - - message = "Completed #{payload[:status]} #{Rack::Utils::HTTP_STATUS_CODES[payload[:status]]} in %.0fms" % event.duration - message << " (#{additions.join(" | ")})" unless additions.blank? - - info(message) - end - - def send_file(event) - message = if event.payload[:x_sendfile] - header = ActionController::Streaming::X_SENDFILE_HEADER - "Sent #{header} header %s" - elsif event.payload[:stream] - "Streamed file %s" - else - "Sent file %s" - end - - message << " (%.1fms)" - info(message % [event.payload[:path], event.duration]) - end - - def redirect_to(event) - info "Redirected to #{event.payload[:location]}" - end - - def send_data(event) - info("Sent data %s (%.1fms)" % [event.payload[:filename], event.duration]) - end - - %w(write_fragment read_fragment exist_fragment? - expire_fragment expire_page write_page).each do |method| - class_eval <<-METHOD, __FILE__, __LINE__ + 1 - def #{method}(event) - key_or_path = event.payload[:key] || event.payload[:path] - human_name = #{method.to_s.humanize.inspect} - info("\#{human_name} \#{key_or_path} (%.1fms)" % event.duration) - end - METHOD - end - - def logger - ActionController::Base.logger - end - end - end -end \ No newline at end of file diff --git a/actionpack/lib/action_view/railtie.rb b/actionpack/lib/action_view/railtie.rb index d9e2557d89..03f18ac172 100644 --- a/actionpack/lib/action_view/railtie.rb +++ b/actionpack/lib/action_view/railtie.rb @@ -5,8 +5,8 @@ module ActionView class Railtie < Rails::Railtie railtie_name :action_view - require "action_view/railties/subscriber" - subscriber ActionView::Railties::Subscriber.new + require "action_view/railties/log_subscriber" + log_subscriber ActionView::Railties::LogSubscriber.new initializer "action_view.cache_asset_timestamps" do |app| unless app.config.cache_classes diff --git a/actionpack/lib/action_view/railties/log_subscriber.rb b/actionpack/lib/action_view/railties/log_subscriber.rb new file mode 100644 index 0000000000..9487a10706 --- /dev/null +++ b/actionpack/lib/action_view/railties/log_subscriber.rb @@ -0,0 +1,24 @@ +module ActionView + module Railties + class LogSubscriber < Rails::LogSubscriber + def render_template(event) + message = "Rendered #{from_rails_root(event.payload[:identifier])}" + message << " within #{from_rails_root(event.payload[:layout])}" if event.payload[:layout] + message << (" (%.1fms)" % event.duration) + info(message) + end + alias :render_partial :render_template + alias :render_collection :render_template + + def logger + ActionController::Base.logger + end + + protected + + def from_rails_root(string) + string.sub("#{Rails.root}/", "").sub(/^app\/views\//, "") + end + end + end +end \ No newline at end of file diff --git a/actionpack/lib/action_view/railties/subscriber.rb b/actionpack/lib/action_view/railties/subscriber.rb deleted file mode 100644 index 803f19379c..0000000000 --- a/actionpack/lib/action_view/railties/subscriber.rb +++ /dev/null @@ -1,24 +0,0 @@ -module ActionView - module Railties - class Subscriber < Rails::Subscriber - def render_template(event) - message = "Rendered #{from_rails_root(event.payload[:identifier])}" - message << " within #{from_rails_root(event.payload[:layout])}" if event.payload[:layout] - message << (" (%.1fms)" % event.duration) - info(message) - end - alias :render_partial :render_template - alias :render_collection :render_template - - def logger - ActionController::Base.logger - end - - protected - - def from_rails_root(string) - string.sub("#{Rails.root}/", "").sub(/^app\/views\//, "") - end - end - end -end \ No newline at end of file diff --git a/actionpack/test/activerecord/controller_runtime_test.rb b/actionpack/test/activerecord/controller_runtime_test.rb index ed8e324938..4d2a7b9b5a 100644 --- a/actionpack/test/activerecord/controller_runtime_test.rb +++ b/actionpack/test/activerecord/controller_runtime_test.rb @@ -1,30 +1,30 @@ require 'active_record_unit' require 'active_record/railties/controller_runtime' require 'fixtures/project' -require 'rails/subscriber/test_helper' -require 'action_controller/railties/subscriber' +require 'rails/log_subscriber/test_helper' +require 'action_controller/railties/log_subscriber' ActionController::Base.send :include, ActiveRecord::Railties::ControllerRuntime -class ControllerRuntimeSubscriberTest < ActionController::TestCase - class SubscriberController < ActionController::Base +class ControllerRuntimeLogSubscriberTest < ActionController::TestCase + class LogSubscriberController < ActionController::Base def show render :inline => "<%= Project.all %>" end end - include Rails::Subscriber::TestHelper - tests SubscriberController + include Rails::LogSubscriber::TestHelper + tests LogSubscriberController def setup @old_logger = ActionController::Base.logger - Rails::Subscriber.add(:action_controller, ActionController::Railties::Subscriber.new) + Rails::LogSubscriber.add(:action_controller, ActionController::Railties::LogSubscriber.new) super end def teardown super - Rails::Subscriber.subscribers.clear + Rails::LogSubscriber.log_subscribers.clear ActionController::Base.logger = @old_logger end diff --git a/actionpack/test/controller/log_subscriber_test.rb b/actionpack/test/controller/log_subscriber_test.rb new file mode 100644 index 0000000000..182f343b2f --- /dev/null +++ b/actionpack/test/controller/log_subscriber_test.rb @@ -0,0 +1,172 @@ +require "abstract_unit" +require "rails/log_subscriber/test_helper" +require "action_controller/railties/log_subscriber" + +module Another + class LogSubscribersController < ActionController::Base + def show + render :nothing => true + end + + def redirector + redirect_to "http://foo.bar/" + end + + def data_sender + send_data "cool data", :filename => "file.txt" + end + + def xfile_sender + send_file File.expand_path("company.rb", FIXTURE_LOAD_PATH), :x_sendfile => true + end + + def file_sender + send_file File.expand_path("company.rb", FIXTURE_LOAD_PATH) + end + + def with_fragment_cache + render :inline => "<%= cache('foo'){ 'bar' } %>" + end + + def with_page_cache + cache_page("Super soaker", "/index.html") + render :nothing => true + end + end +end + +class ACLogSubscriberTest < ActionController::TestCase + tests Another::LogSubscribersController + include Rails::LogSubscriber::TestHelper + + def setup + @old_logger = ActionController::Base.logger + + @cache_path = File.expand_path('../temp/test_cache', File.dirname(__FILE__)) + ActionController::Base.page_cache_directory = @cache_path + ActionController::Base.cache_store = :file_store, @cache_path + + Rails::LogSubscriber.add(:action_controller, ActionController::Railties::LogSubscriber.new) + super + end + + def teardown + super + Rails::LogSubscriber.log_subscribers.clear + FileUtils.rm_rf(@cache_path) + ActionController::Base.logger = @old_logger + end + + def set_logger(logger) + ActionController::Base.logger = logger + end + + def test_start_processing + get :show + wait + assert_equal 2, logs.size + assert_equal "Processing by Another::LogSubscribersController#show as HTML", logs.first + end + + def test_process_action + get :show + wait + assert_equal 2, logs.size + assert_match /Completed/, logs.last + assert_match /200 OK/, logs.last + end + + def test_process_action_without_parameters + get :show + wait + assert_nil logs.detect {|l| l =~ /Parameters/ } + end + + def test_process_action_with_parameters + get :show, :id => '10' + wait + + assert_equal 3, logs.size + assert_equal 'Parameters: {"id"=>"10"}', logs[1] + end + + def test_process_action_with_view_runtime + get :show + wait + assert_match /\(Views: [\d\.]+ms\)/, logs[1] + end + + def test_process_action_with_filter_parameters + @request.env["action_dispatch.parameter_filter"] = [:lifo, :amount] + + get :show, :lifo => 'Pratik', :amount => '420', :step => '1' + wait + + params = logs[1] + assert_match /"amount"=>"\[FILTERED\]"/, params + assert_match /"lifo"=>"\[FILTERED\]"/, params + assert_match /"step"=>"1"/, params + end + + def test_redirect_to + get :redirector + wait + + assert_equal 3, logs.size + assert_equal "Redirected to http://foo.bar/", logs[1] + end + + def test_send_data + get :data_sender + wait + + assert_equal 3, logs.size + assert_match /Sent data file\.txt/, logs[1] + end + + def test_send_file + get :file_sender + wait + + assert_equal 3, logs.size + assert_match /Sent file/, logs[1] + assert_match /test\/fixtures\/company\.rb/, logs[1] + end + + def test_send_xfile + get :xfile_sender + wait + + assert_equal 3, logs.size + assert_match /Sent X\-Sendfile header/, logs[1] + assert_match /test\/fixtures\/company\.rb/, logs[1] + end + + def test_with_fragment_cache + ActionController::Base.perform_caching = true + get :with_fragment_cache + wait + + assert_equal 4, logs.size + assert_match /Exist fragment\? views\/foo/, logs[1] + assert_match /Write fragment views\/foo/, logs[2] + ensure + ActionController::Base.perform_caching = true + end + + def test_with_page_cache + ActionController::Base.perform_caching = true + get :with_page_cache + wait + + assert_equal 3, logs.size + assert_match /Write page/, logs[1] + assert_match /\/index\.html/, logs[1] + ensure + ActionController::Base.perform_caching = true + end + + def logs + @logs ||= @logger.logged(:info) + end +end diff --git a/actionpack/test/controller/subscriber_test.rb b/actionpack/test/controller/subscriber_test.rb deleted file mode 100644 index d7c1166f14..0000000000 --- a/actionpack/test/controller/subscriber_test.rb +++ /dev/null @@ -1,172 +0,0 @@ -require "abstract_unit" -require "rails/subscriber/test_helper" -require "action_controller/railties/subscriber" - -module Another - class SubscribersController < ActionController::Base - def show - render :nothing => true - end - - def redirector - redirect_to "http://foo.bar/" - end - - def data_sender - send_data "cool data", :filename => "file.txt" - end - - def xfile_sender - send_file File.expand_path("company.rb", FIXTURE_LOAD_PATH), :x_sendfile => true - end - - def file_sender - send_file File.expand_path("company.rb", FIXTURE_LOAD_PATH) - end - - def with_fragment_cache - render :inline => "<%= cache('foo'){ 'bar' } %>" - end - - def with_page_cache - cache_page("Super soaker", "/index.html") - render :nothing => true - end - end -end - -class ACSubscriberTest < ActionController::TestCase - tests Another::SubscribersController - include Rails::Subscriber::TestHelper - - def setup - @old_logger = ActionController::Base.logger - - @cache_path = File.expand_path('../temp/test_cache', File.dirname(__FILE__)) - ActionController::Base.page_cache_directory = @cache_path - ActionController::Base.cache_store = :file_store, @cache_path - - Rails::Subscriber.add(:action_controller, ActionController::Railties::Subscriber.new) - super - end - - def teardown - super - Rails::Subscriber.subscribers.clear - FileUtils.rm_rf(@cache_path) - ActionController::Base.logger = @old_logger - end - - def set_logger(logger) - ActionController::Base.logger = logger - end - - def test_start_processing - get :show - wait - assert_equal 2, logs.size - assert_equal "Processing by Another::SubscribersController#show as HTML", logs.first - end - - def test_process_action - get :show - wait - assert_equal 2, logs.size - assert_match /Completed/, logs.last - assert_match /200 OK/, logs.last - end - - def test_process_action_without_parameters - get :show - wait - assert_nil logs.detect {|l| l =~ /Parameters/ } - end - - def test_process_action_with_parameters - get :show, :id => '10' - wait - - assert_equal 3, logs.size - assert_equal 'Parameters: {"id"=>"10"}', logs[1] - end - - def test_process_action_with_view_runtime - get :show - wait - assert_match /\(Views: [\d\.]+ms\)/, logs[1] - end - - def test_process_action_with_filter_parameters - @request.env["action_dispatch.parameter_filter"] = [:lifo, :amount] - - get :show, :lifo => 'Pratik', :amount => '420', :step => '1' - wait - - params = logs[1] - assert_match /"amount"=>"\[FILTERED\]"/, params - assert_match /"lifo"=>"\[FILTERED\]"/, params - assert_match /"step"=>"1"/, params - end - - def test_redirect_to - get :redirector - wait - - assert_equal 3, logs.size - assert_equal "Redirected to http://foo.bar/", logs[1] - end - - def test_send_data - get :data_sender - wait - - assert_equal 3, logs.size - assert_match /Sent data file\.txt/, logs[1] - end - - def test_send_file - get :file_sender - wait - - assert_equal 3, logs.size - assert_match /Sent file/, logs[1] - assert_match /test\/fixtures\/company\.rb/, logs[1] - end - - def test_send_xfile - get :xfile_sender - wait - - assert_equal 3, logs.size - assert_match /Sent X\-Sendfile header/, logs[1] - assert_match /test\/fixtures\/company\.rb/, logs[1] - end - - def test_with_fragment_cache - ActionController::Base.perform_caching = true - get :with_fragment_cache - wait - - assert_equal 4, logs.size - assert_match /Exist fragment\? views\/foo/, logs[1] - assert_match /Write fragment views\/foo/, logs[2] - ensure - ActionController::Base.perform_caching = true - end - - def test_with_page_cache - ActionController::Base.perform_caching = true - get :with_page_cache - wait - - assert_equal 3, logs.size - assert_match /Write page/, logs[1] - assert_match /\/index\.html/, logs[1] - ensure - ActionController::Base.perform_caching = true - end - - def logs - @logs ||= @logger.logged(:info) - end -end diff --git a/actionpack/test/template/log_subscriber_test.rb b/actionpack/test/template/log_subscriber_test.rb new file mode 100644 index 0000000000..2eb2484cf5 --- /dev/null +++ b/actionpack/test/template/log_subscriber_test.rb @@ -0,0 +1,93 @@ +require "abstract_unit" +require "rails/log_subscriber/test_helper" +require "action_view/railties/log_subscriber" +require "controller/fake_models" + +class AVLogSubscriberTest < ActiveSupport::TestCase + include Rails::LogSubscriber::TestHelper + + def setup + @old_logger = ActionController::Base.logger + @view = ActionView::Base.new(ActionController::Base.view_paths, {}) + Rails.stubs(:root).returns(File.expand_path(FIXTURE_LOAD_PATH)) + Rails::LogSubscriber.add(:action_view, ActionView::Railties::LogSubscriber.new) + super + end + + def teardown + super + Rails::LogSubscriber.log_subscribers.clear + ActionController::Base.logger = @old_logger + end + + def set_logger(logger) + ActionController::Base.logger = logger + end + + def test_render_file_template + @view.render(:file => "test/hello_world.erb") + wait + + assert_equal 1, @logger.logged(:info).size + assert_match /Rendered test\/hello_world\.erb/, @logger.logged(:info).last + end + + def test_render_text_template + @view.render(:text => "TEXT") + wait + + assert_equal 1, @logger.logged(:info).size + assert_match /Rendered text template/, @logger.logged(:info).last + end + + def test_render_inline_template + @view.render(:inline => "<%= 'TEXT' %>") + wait + + assert_equal 1, @logger.logged(:info).size + assert_match /Rendered inline template/, @logger.logged(:info).last + end + + def test_render_partial_template + @view.render(:partial => "test/customer") + wait + + assert_equal 1, @logger.logged(:info).size + assert_match /Rendered test\/_customer.erb/, @logger.logged(:info).last + end + + def test_render_partial_with_implicit_path + @view.stubs(:controller_path).returns("test") + @view.render(Customer.new("david"), :greeting => "hi") + wait + + assert_equal 1, @logger.logged(:info).size + assert_match /Rendered customers\/_customer\.html\.erb/, @logger.logged(:info).last + end + + def test_render_collection_template + @view.render(:partial => "test/customer", :collection => [ Customer.new("david"), Customer.new("mary") ]) + wait + + assert_equal 1, @logger.logged(:info).size + assert_match /Rendered test\/_customer.erb/, @logger.logged(:info).last + end + + def test_render_collection_with_implicit_path + @view.stubs(:controller_path).returns("test") + @view.render([ Customer.new("david"), Customer.new("mary") ], :greeting => "hi") + wait + + assert_equal 1, @logger.logged(:info).size + assert_match /Rendered customers\/_customer\.html\.erb/, @logger.logged(:info).last + end + + def test_render_collection_template_without_path + @view.stubs(:controller_path).returns("test") + @view.render([ GoodCustomer.new("david"), Customer.new("mary") ], :greeting => "hi") + wait + + assert_equal 1, @logger.logged(:info).size + assert_match /Rendered collection/, @logger.logged(:info).last + end +end \ No newline at end of file diff --git a/actionpack/test/template/subscriber_test.rb b/actionpack/test/template/subscriber_test.rb deleted file mode 100644 index 8bacab7088..0000000000 --- a/actionpack/test/template/subscriber_test.rb +++ /dev/null @@ -1,93 +0,0 @@ -require "abstract_unit" -require "rails/subscriber/test_helper" -require "action_view/railties/subscriber" -require "controller/fake_models" - -class AVSubscriberTest < ActiveSupport::TestCase - include Rails::Subscriber::TestHelper - - def setup - @old_logger = ActionController::Base.logger - @view = ActionView::Base.new(ActionController::Base.view_paths, {}) - Rails.stubs(:root).returns(File.expand_path(FIXTURE_LOAD_PATH)) - Rails::Subscriber.add(:action_view, ActionView::Railties::Subscriber.new) - super - end - - def teardown - super - Rails::Subscriber.subscribers.clear - ActionController::Base.logger = @old_logger - end - - def set_logger(logger) - ActionController::Base.logger = logger - end - - def test_render_file_template - @view.render(:file => "test/hello_world.erb") - wait - - assert_equal 1, @logger.logged(:info).size - assert_match /Rendered test\/hello_world\.erb/, @logger.logged(:info).last - end - - def test_render_text_template - @view.render(:text => "TEXT") - wait - - assert_equal 1, @logger.logged(:info).size - assert_match /Rendered text template/, @logger.logged(:info).last - end - - def test_render_inline_template - @view.render(:inline => "<%= 'TEXT' %>") - wait - - assert_equal 1, @logger.logged(:info).size - assert_match /Rendered inline template/, @logger.logged(:info).last - end - - def test_render_partial_template - @view.render(:partial => "test/customer") - wait - - assert_equal 1, @logger.logged(:info).size - assert_match /Rendered test\/_customer.erb/, @logger.logged(:info).last - end - - def test_render_partial_with_implicit_path - @view.stubs(:controller_path).returns("test") - @view.render(Customer.new("david"), :greeting => "hi") - wait - - assert_equal 1, @logger.logged(:info).size - assert_match /Rendered customers\/_customer\.html\.erb/, @logger.logged(:info).last - end - - def test_render_collection_template - @view.render(:partial => "test/customer", :collection => [ Customer.new("david"), Customer.new("mary") ]) - wait - - assert_equal 1, @logger.logged(:info).size - assert_match /Rendered test\/_customer.erb/, @logger.logged(:info).last - end - - def test_render_collection_with_implicit_path - @view.stubs(:controller_path).returns("test") - @view.render([ Customer.new("david"), Customer.new("mary") ], :greeting => "hi") - wait - - assert_equal 1, @logger.logged(:info).size - assert_match /Rendered customers\/_customer\.html\.erb/, @logger.logged(:info).last - end - - def test_render_collection_template_without_path - @view.stubs(:controller_path).returns("test") - @view.render([ GoodCustomer.new("david"), Customer.new("mary") ], :greeting => "hi") - wait - - assert_equal 1, @logger.logged(:info).size - assert_match /Rendered collection/, @logger.logged(:info).last - end -end \ No newline at end of file diff --git a/activerecord/lib/active_record/base.rb b/activerecord/lib/active_record/base.rb index f30eba4f06..c6dde078ca 100755 --- a/activerecord/lib/active_record/base.rb +++ b/activerecord/lib/active_record/base.rb @@ -552,7 +552,7 @@ module ActiveRecord #:nodoc: def colorize_logging(*args) ActiveSupport::Deprecation.warn "ActiveRecord::Base.colorize_logging and " << "config.active_record.colorize_logging are deprecated. Please use " << - "Rails::Subscriber.colorize_logging or config.colorize_logging instead", caller + "Rails::LogSubscriber.colorize_logging or config.colorize_logging instead", caller end alias :colorize_logging= :colorize_logging diff --git a/activerecord/lib/active_record/railtie.rb b/activerecord/lib/active_record/railtie.rb index e70b0d1bfb..b38bd9a644 100644 --- a/activerecord/lib/active_record/railtie.rb +++ b/activerecord/lib/active_record/railtie.rb @@ -20,8 +20,8 @@ module ActiveRecord end # TODO If we require the wrong file, the error never comes up. - require "active_record/railties/subscriber" - subscriber ActiveRecord::Railties::Subscriber.new + require "active_record/railties/log_subscriber" + log_subscriber ActiveRecord::Railties::LogSubscriber.new initializer "active_record.initialize_timezone" do ActiveRecord::Base.time_zone_aware_attributes = true diff --git a/activerecord/lib/active_record/railties/log_subscriber.rb b/activerecord/lib/active_record/railties/log_subscriber.rb new file mode 100644 index 0000000000..48b25032ce --- /dev/null +++ b/activerecord/lib/active_record/railties/log_subscriber.rb @@ -0,0 +1,27 @@ +module ActiveRecord + module Railties + class LogSubscriber < Rails::LogSubscriber + def sql(event) + name = '%s (%.1fms)' % [event.payload[:name], event.duration] + sql = event.payload[:sql].squeeze(' ') + + if odd? + name = color(name, :cyan, true) + sql = color(sql, nil, true) + else + name = color(name, :magenta, true) + end + + debug " #{name} #{sql}" + end + + def odd? + @odd_or_even = !@odd_or_even + end + + def logger + ActiveRecord::Base.logger + end + end + end +end \ No newline at end of file diff --git a/activerecord/lib/active_record/railties/subscriber.rb b/activerecord/lib/active_record/railties/subscriber.rb deleted file mode 100644 index fd873dbff8..0000000000 --- a/activerecord/lib/active_record/railties/subscriber.rb +++ /dev/null @@ -1,27 +0,0 @@ -module ActiveRecord - module Railties - class Subscriber < Rails::Subscriber - def sql(event) - name = '%s (%.1fms)' % [event.payload[:name], event.duration] - sql = event.payload[:sql].squeeze(' ') - - if odd? - name = color(name, :cyan, true) - sql = color(sql, nil, true) - else - name = color(name, :magenta, true) - end - - debug " #{name} #{sql}" - end - - def odd? - @odd_or_even = !@odd_or_even - end - - def logger - ActiveRecord::Base.logger - end - end - end -end \ No newline at end of file diff --git a/activerecord/test/cases/log_subscriber_test.rb b/activerecord/test/cases/log_subscriber_test.rb new file mode 100644 index 0000000000..f0197ddf77 --- /dev/null +++ b/activerecord/test/cases/log_subscriber_test.rb @@ -0,0 +1,42 @@ +require "cases/helper" +require "models/developer" +require "rails/log_subscriber/test_helper" +require "active_record/railties/log_subscriber" + +class LogSubscriberTest < ActiveSupport::TestCase + include Rails::LogSubscriber::TestHelper + Rails::LogSubscriber.add(:active_record, ActiveRecord::Railties::LogSubscriber.new) + + def setup + @old_logger = ActiveRecord::Base.logger + super + end + + def teardown + super + ActiveRecord::Base.logger = @old_logger + end + + def set_logger(logger) + ActiveRecord::Base.logger = logger + end + + def test_basic_query_logging + Developer.all + wait + assert_equal 1, @logger.logged(:debug).size + assert_match /Developer Load/, @logger.logged(:debug).last + assert_match /SELECT .*?FROM .?developers.?/, @logger.logged(:debug).last + end + + def test_cached_queries + ActiveRecord::Base.cache do + Developer.all + Developer.all + end + wait + assert_equal 2, @logger.logged(:debug).size + assert_match /CACHE/, @logger.logged(:debug).last + assert_match /SELECT .*?FROM .?developers.?/, @logger.logged(:debug).last + end +end \ No newline at end of file diff --git a/activerecord/test/cases/subscriber_test.rb b/activerecord/test/cases/subscriber_test.rb deleted file mode 100644 index 5328d4468b..0000000000 --- a/activerecord/test/cases/subscriber_test.rb +++ /dev/null @@ -1,42 +0,0 @@ -require "cases/helper" -require "models/developer" -require "rails/subscriber/test_helper" -require "active_record/railties/subscriber" - -class SubscriberTest < ActiveSupport::TestCase - include Rails::Subscriber::TestHelper - Rails::Subscriber.add(:active_record, ActiveRecord::Railties::Subscriber.new) - - def setup - @old_logger = ActiveRecord::Base.logger - super - end - - def teardown - super - ActiveRecord::Base.logger = @old_logger - end - - def set_logger(logger) - ActiveRecord::Base.logger = logger - end - - def test_basic_query_logging - Developer.all - wait - assert_equal 1, @logger.logged(:debug).size - assert_match /Developer Load/, @logger.logged(:debug).last - assert_match /SELECT .*?FROM .?developers.?/, @logger.logged(:debug).last - end - - def test_cached_queries - ActiveRecord::Base.cache do - Developer.all - Developer.all - end - wait - assert_equal 2, @logger.logged(:debug).size - assert_match /CACHE/, @logger.logged(:debug).last - assert_match /SELECT .*?FROM .?developers.?/, @logger.logged(:debug).last - end -end \ No newline at end of file diff --git a/activeresource/lib/active_resource/railtie.rb b/activeresource/lib/active_resource/railtie.rb index 7e35fdc0eb..27c88415f6 100644 --- a/activeresource/lib/active_resource/railtie.rb +++ b/activeresource/lib/active_resource/railtie.rb @@ -5,8 +5,8 @@ module ActiveResource class Railtie < Rails::Railtie railtie_name :active_resource - require "active_resource/railties/subscriber" - subscriber ActiveResource::Railties::Subscriber.new + require "active_resource/railties/log_subscriber" + log_subscriber ActiveResource::Railties::LogSubscriber.new initializer "active_resource.set_configs" do |app| app.config.active_resource.each do |k,v| diff --git a/activeresource/lib/active_resource/railties/log_subscriber.rb b/activeresource/lib/active_resource/railties/log_subscriber.rb new file mode 100644 index 0000000000..86806a93d0 --- /dev/null +++ b/activeresource/lib/active_resource/railties/log_subscriber.rb @@ -0,0 +1,15 @@ +module ActiveResource + module Railties + class LogSubscriber < Rails::LogSubscriber + def request(event) + result = event.payload[:result] + info "#{event.payload[:method].to_s.upcase} #{event.payload[:request_uri]}" + info "--> %d %s %d (%.1fms)" % [result.code, result.message, result.body.to_s.length, event.duration] + end + + def logger + ActiveResource::Base.logger + end + end + end +end \ No newline at end of file diff --git a/activeresource/lib/active_resource/railties/subscriber.rb b/activeresource/lib/active_resource/railties/subscriber.rb deleted file mode 100644 index fb98061b71..0000000000 --- a/activeresource/lib/active_resource/railties/subscriber.rb +++ /dev/null @@ -1,15 +0,0 @@ -module ActiveResource - module Railties - class Subscriber < Rails::Subscriber - def request(event) - result = event.payload[:result] - info "#{event.payload[:method].to_s.upcase} #{event.payload[:request_uri]}" - info "--> %d %s %d (%.1fms)" % [result.code, result.message, result.body.to_s.length, event.duration] - end - - def logger - ActiveResource::Base.logger - end - end - end -end \ No newline at end of file diff --git a/activeresource/test/cases/log_subscriber_test.rb b/activeresource/test/cases/log_subscriber_test.rb new file mode 100644 index 0000000000..56709b6fd3 --- /dev/null +++ b/activeresource/test/cases/log_subscriber_test.rb @@ -0,0 +1,31 @@ +require "abstract_unit" +require "fixtures/person" +require "rails/log_subscriber/test_helper" +require "active_resource/railties/log_subscriber" +require "active_support/core_ext/hash/conversions" + +class LogSubscriberTest < ActiveSupport::TestCase + include Rails::LogSubscriber::TestHelper + Rails::LogSubscriber.add(:active_resource, ActiveResource::Railties::LogSubscriber.new) + + def setup + @matz = { :id => 1, :name => 'Matz' }.to_xml(:root => 'person') + ActiveResource::HttpMock.respond_to do |mock| + mock.get "/people/1.xml", {}, @matz + end + + super + end + + def set_logger(logger) + ActiveResource::Base.logger = logger + end + + def test_request_notification + matz = Person.find(1) + wait + assert_equal 2, @logger.logged(:info).size + assert_equal "GET http://37s.sunrise.i:3000/people/1.xml", @logger.logged(:info)[0] + assert_match /\-\-\> 200 200 106/, @logger.logged(:info)[1] + end +end \ No newline at end of file diff --git a/activeresource/test/cases/subscriber_test.rb b/activeresource/test/cases/subscriber_test.rb deleted file mode 100644 index fb890e86cb..0000000000 --- a/activeresource/test/cases/subscriber_test.rb +++ /dev/null @@ -1,31 +0,0 @@ -require "abstract_unit" -require "fixtures/person" -require "rails/subscriber/test_helper" -require "active_resource/railties/subscriber" -require "active_support/core_ext/hash/conversions" - -class SubscriberTest < ActiveSupport::TestCase - include Rails::Subscriber::TestHelper - Rails::Subscriber.add(:active_resource, ActiveResource::Railties::Subscriber.new) - - def setup - @matz = { :id => 1, :name => 'Matz' }.to_xml(:root => 'person') - ActiveResource::HttpMock.respond_to do |mock| - mock.get "/people/1.xml", {}, @matz - end - - super - end - - def set_logger(logger) - ActiveResource::Base.logger = logger - end - - def test_request_notification - matz = Person.find(1) - wait - assert_equal 2, @logger.logged(:info).size - assert_equal "GET http://37s.sunrise.i:3000/people/1.xml", @logger.logged(:info)[0] - assert_match /\-\-\> 200 200 106/, @logger.logged(:info)[1] - end -end \ No newline at end of file diff --git a/activesupport/lib/active_support/notifications.rb b/activesupport/lib/active_support/notifications.rb index 3e96decb8c..06d57765bc 100644 --- a/activesupport/lib/active_support/notifications.rb +++ b/activesupport/lib/active_support/notifications.rb @@ -9,7 +9,7 @@ module ActiveSupport # end # # You can consume those events and the information they provide by registering - # a subscriber. For instance, let's store all instrumented events in an array: + # a log subscriber. For instance, let's store all instrumented events in an array: # # @events = [] # @@ -35,7 +35,7 @@ module ActiveSupport # end # # Notifications ships with a queue implementation that consumes and publish events - # to subscribers in a thread. You can use any queue implementation you want. + # to log subscribers in a thread. You can use any queue implementation you want. # module Notifications autoload :Instrumenter, 'active_support/notifications/instrumenter' diff --git a/activesupport/lib/active_support/notifications/fanout.rb b/activesupport/lib/active_support/notifications/fanout.rb index 0ec23da073..05de4946a5 100644 --- a/activesupport/lib/active_support/notifications/fanout.rb +++ b/activesupport/lib/active_support/notifications/fanout.rb @@ -1,10 +1,10 @@ module ActiveSupport module Notifications # This is a default queue implementation that ships with Notifications. It - # just pushes events to all registered subscribers. + # just pushes events to all registered log subscribers. class Fanout def initialize - @subscribers = [] + @log_subscribers = [] end def bind(pattern) @@ -12,11 +12,11 @@ module ActiveSupport end def subscribe(pattern = nil, &block) - @subscribers << Subscriber.new(pattern, &block) + @log_subscribers << LogSubscriber.new(pattern, &block) end def publish(*args) - @subscribers.each { |s| s.publish(*args) } + @log_subscribers.each { |s| s.publish(*args) } end # This is a sync queue, so there is not waiting. @@ -41,7 +41,7 @@ module ActiveSupport end end - class Subscriber #:nodoc: + class LogSubscriber #:nodoc: def initialize(pattern, &block) @pattern = pattern @block = block diff --git a/activesupport/test/notifications_test.rb b/activesupport/test/notifications_test.rb index 545811a376..779771553c 100644 --- a/activesupport/test/notifications_test.rb +++ b/activesupport/test/notifications_test.rb @@ -26,7 +26,7 @@ module Notifications assert_equal [[:foo]], @events end - def test_subscriber_with_pattern + def test_log_subscriber_with_pattern events = [] @notifier.subscribe('1') { |*args| events << args } @@ -38,7 +38,7 @@ module Notifications assert_equal [['1'], ['1.a']], events end - def test_subscriber_with_pattern_as_regexp + def test_log_subscriber_with_pattern_as_regexp events = [] @notifier.subscribe(/\d/) { |*args| events << args } @@ -50,7 +50,7 @@ module Notifications assert_equal [['1'], ['a.1'], ['1.a']], events end - def test_multiple_subscribers + def test_multiple_log_subscribers @another = [] @notifier.subscribe { |*args| @another << args } @notifier.publish :foo diff --git a/railties/guides/source/3_0_release_notes.textile b/railties/guides/source/3_0_release_notes.textile index 639e775bf5..4b0dc72908 100644 --- a/railties/guides/source/3_0_release_notes.textile +++ b/railties/guides/source/3_0_release_notes.textile @@ -435,7 +435,7 @@ As well as the following deprecations: * I18n error messages for ActiveRecord should be changed from :en.activerecord.errors.template to :en.errors.template. * model.errors.on is deprecated in favour of model.errors[] * validates_presence_of => validates... :presence => true -* ActiveRecord::Base.colorize_logging and config.active_record.colorize_logging are deprecated in favour of Rails::Subscriber.colorize_logging or config.colorize_logging +* ActiveRecord::Base.colorize_logging and config.active_record.colorize_logging are deprecated in favour of Rails::LogSubscriber.colorize_logging or config.colorize_logging NOTE: While an implementation of State Machine has been in Active Record edge for some months now, it has been removed from the Rails 3.0 release. diff --git a/railties/lib/rails.rb b/railties/lib/rails.rb index b7a39fd5a7..3d3151bd8f 100644 --- a/railties/lib/rails.rb +++ b/railties/lib/rails.rb @@ -7,7 +7,7 @@ require 'active_support/core_ext/logger' require 'rails/application' require 'rails/version' require 'rails/deprecation' -require 'rails/subscriber' +require 'rails/log_subscriber' require 'rails/ruby_version_check' require 'active_support/railtie' diff --git a/railties/lib/rails/application/bootstrap.rb b/railties/lib/rails/application/bootstrap.rb index b20e53f2de..0714b34b31 100644 --- a/railties/lib/rails/application/bootstrap.rb +++ b/railties/lib/rails/application/bootstrap.rb @@ -49,17 +49,17 @@ module Rails end end - # Initialize rails subscriber on top of notifications. - initializer :initialize_subscriber do + # Initialize rails log subscriber on top of notifications. + initializer :initialize_log_subscriber do require 'active_support/notifications' if config.colorize_logging == false - Rails::Subscriber.colorize_logging = false + Rails::LogSubscriber.colorize_logging = false config.generators.colorize_logging = false end ActiveSupport::Notifications.subscribe do |*args| - Rails::Subscriber.dispatch(args) + Rails::LogSubscriber.dispatch(args) end end diff --git a/railties/lib/rails/log_subscriber.rb b/railties/lib/rails/log_subscriber.rb new file mode 100644 index 0000000000..c867b92b6b --- /dev/null +++ b/railties/lib/rails/log_subscriber.rb @@ -0,0 +1,108 @@ +require 'active_support/core_ext/class/inheritable_attributes' +require 'active_support/notifications' + +module Rails + # Rails::LogSubscriber is an object set to consume ActiveSupport::Notifications + # on initialization with solely purpose of logging. The log subscriber dispatches + # notifications to a regirested object based on its given namespace. + # + # An example would be ActiveRecord log subscriber responsible for logging queries: + # + # module ActiveRecord + # class Railtie + # class LogSubscriber < Rails::LogSubscriber + # def sql(event) + # "#{event.payload[:name]} (#{event.duration}) #{event.payload[:sql]}" + # end + # end + # end + # end + # + # It's finally registed as: + # + # Rails::LogSubscriber.add :active_record, ActiveRecord::Railtie::LogSubscriber.new + # + # So whenever a "active_record.sql" notification arrive to Rails::LogSubscriber, + # it will properly dispatch the event (ActiveSupport::Notifications::Event) to + # the sql method. + # + # This is useful because it avoids spanning several log subscribers just for logging + # purposes(which slows down the main thread). Besides of providing a centralized + # facility on top of Rails.logger. + # + # Log subscriber also has some helpers to deal with logging and automatically flushes + # all logs when the request finishes (via action_dispatch.callback notification). + class LogSubscriber + mattr_accessor :colorize_logging + self.colorize_logging = true + + # Embed in a String to clear all previous ANSI sequences. + CLEAR = "\e[0m" + BOLD = "\e[1m" + + # Colors + BLACK = "\e[30m" + RED = "\e[31m" + GREEN = "\e[32m" + YELLOW = "\e[33m" + BLUE = "\e[34m" + MAGENTA = "\e[35m" + CYAN = "\e[36m" + WHITE = "\e[37m" + + def self.add(namespace, log_subscriber) + log_subscribers[namespace.to_sym] = log_subscriber + end + + def self.log_subscribers + @log_subscribers ||= {} + end + + def self.dispatch(args) + namespace, name = args[0].split(".") + log_subscriber = log_subscribers[namespace.to_sym] + + if log_subscriber.respond_to?(name) && log_subscriber.logger + begin + log_subscriber.send(name, ActiveSupport::Notifications::Event.new(*args)) + rescue Exception => e + Rails.logger.error "Could not log #{args[0].inspect} event. #{e.class}: #{e.message}" + end + end + end + + # Flush all log_subscribers' logger. + def self.flush_all! + loggers = log_subscribers.values.map(&:logger) + loggers.uniq! + loggers.each { |l| l.flush if l.respond_to?(:flush) } + end + + # By default, we use the Rails.logger for logging. + def logger + Rails.logger + end + + protected + + %w(info debug warn error fatal unknown).each do |level| + class_eval <<-METHOD, __FILE__, __LINE__ + 1 + def #{level}(*args, &block) + logger.#{level}(*args, &block) + end + METHOD + end + + # Set color by using a string or one of the defined constants. If a third + # option is set to true, it also adds bold to the string. This is based + # on Highline implementation and it automatically appends CLEAR to the end + # of the returned String. + # + def color(text, color, bold=false) + return text unless colorize_logging + color = self.class.const_get(color.to_s.upcase) if color.is_a?(Symbol) + bold = bold ? BOLD : "" + "#{bold}#{color}#{text}#{CLEAR}" + end + end +end \ No newline at end of file diff --git a/railties/lib/rails/log_subscriber/test_helper.rb b/railties/lib/rails/log_subscriber/test_helper.rb new file mode 100644 index 0000000000..9ede56cad4 --- /dev/null +++ b/railties/lib/rails/log_subscriber/test_helper.rb @@ -0,0 +1,98 @@ +require 'rails/log_subscriber' + +module Rails + class LogSubscriber + # Provides some helpers to deal with testing log subscribers by setting up + # notifications. Take for instance ActiveRecord subscriber tests: + # + # class SyncLogSubscriberTest < ActiveSupport::TestCase + # include Rails::LogSubscriber::TestHelper + # Rails::LogSubscriber.add(:active_record, ActiveRecord::Railties::LogSubscriber.new) + # + # def test_basic_query_logging + # Developer.all + # wait + # assert_equal 1, @logger.logged(:debug).size + # assert_match /Developer Load/, @logger.logged(:debug).last + # assert_match /SELECT \* FROM "developers"/, @logger.logged(:debug).last + # end + # + # class SyncLogSubscriberTest < ActiveSupport::TestCase + # include Rails::LogSubscriber::SyncTestHelper + # include LogSubscriberTest + # end + # + # class AsyncLogSubscriberTest < ActiveSupport::TestCase + # include Rails::LogSubscriber::AsyncTestHelper + # include LogSubscriberTest + # end + # end + # + # All you need to do is to ensure that your log subscriber is added to Rails::Subscriber, + # as in the second line of the code above. The test helpers is reponsible for setting + # up the queue, subscriptions and turning colors in logs off. + # + # The messages are available in the @logger instance, which is a logger with limited + # powers (it actually do not send anything to your output), and you can collect them + # doing @logger.logged(level), where level is the level used in logging, like info, + # debug, warn and so on. + # + module TestHelper + def setup + @logger = MockLogger.new + @notifier = ActiveSupport::Notifications::Notifier.new(queue) + + Rails::LogSubscriber.colorize_logging = false + @notifier.subscribe { |*args| Rails::LogSubscriber.dispatch(args) } + + set_logger(@logger) + ActiveSupport::Notifications.notifier = @notifier + end + + def teardown + set_logger(nil) + ActiveSupport::Notifications.notifier = nil + end + + class MockLogger + attr_reader :flush_count + + def initialize + @flush_count = 0 + @logged = Hash.new { |h,k| h[k] = [] } + end + + def method_missing(level, message) + @logged[level] << message + end + + def logged(level) + @logged[level].compact.map { |l| l.to_s.strip } + end + + def flush + @flush_count += 1 + end + end + + # Wait notifications to be published. + def wait + @notifier.wait + end + + # Overwrite if you use another logger in your log subscriber: + # + # def logger + # ActiveRecord::Base.logger = @logger + # end + # + def set_logger(logger) + Rails.logger = logger + end + + def queue + ActiveSupport::Notifications::Fanout.new + end + end + end +end \ No newline at end of file diff --git a/railties/lib/rails/rack/logger.rb b/railties/lib/rails/rack/logger.rb index de21fb4f10..2efe224e94 100644 --- a/railties/lib/rails/rack/logger.rb +++ b/railties/lib/rails/rack/logger.rb @@ -1,9 +1,9 @@ -require 'rails/subscriber' +require 'rails/log_subscriber' module Rails module Rack # Log the request started and flush all loggers after it. - class Logger < Rails::Subscriber + class Logger < Rails::LogSubscriber def initialize(app) @app = app end @@ -26,7 +26,7 @@ module Rails end def after_dispatch(env) - Rails::Subscriber.flush_all! + Rails::LogSubscriber.flush_all! end end diff --git a/railties/lib/rails/railtie.rb b/railties/lib/rails/railtie.rb index c038d0ac70..67afae5862 100644 --- a/railties/lib/rails/railtie.rb +++ b/railties/lib/rails/railtie.rb @@ -32,8 +32,8 @@ module Rails subclasses.map { |p| p.railtie_name } end - def subscriber(subscriber) - Rails::Subscriber.add(railtie_name, subscriber) + def log_subscriber(log_subscriber) + Rails::LogSubscriber.add(railtie_name, log_subscriber) end def rake_tasks(&blk) diff --git a/railties/lib/rails/subscriber.rb b/railties/lib/rails/subscriber.rb deleted file mode 100644 index 8c62f562d9..0000000000 --- a/railties/lib/rails/subscriber.rb +++ /dev/null @@ -1,108 +0,0 @@ -require 'active_support/core_ext/class/inheritable_attributes' -require 'active_support/notifications' - -module Rails - # Rails::Subscriber is an object set to consume ActiveSupport::Notifications - # on initialization with solely purpose of logging. The subscriber dispatches - # notifications to a regirested object based on its given namespace. - # - # An example would be ActiveRecord subscriber responsible for logging queries: - # - # module ActiveRecord - # class Railtie - # class Subscriber < Rails::Subscriber - # def sql(event) - # "#{event.payload[:name]} (#{event.duration}) #{event.payload[:sql]}" - # end - # end - # end - # end - # - # It's finally registed as: - # - # Rails::Subscriber.add :active_record, ActiveRecord::Railtie::Subscriber.new - # - # So whenever a "active_record.sql" notification arrive to Rails::Subscriber, - # it will properly dispatch the event (ActiveSupport::Notifications::Event) to - # the sql method. - # - # This is useful because it avoids spanning several subscribers just for logging - # purposes(which slows down the main thread). Besides of providing a centralized - # facility on top of Rails.logger. - # - # Subscriber also has some helpers to deal with logging and automatically flushes - # all logs when the request finishes (via action_dispatch.callback notification). - class Subscriber - mattr_accessor :colorize_logging - self.colorize_logging = true - - # Embed in a String to clear all previous ANSI sequences. - CLEAR = "\e[0m" - BOLD = "\e[1m" - - # Colors - BLACK = "\e[30m" - RED = "\e[31m" - GREEN = "\e[32m" - YELLOW = "\e[33m" - BLUE = "\e[34m" - MAGENTA = "\e[35m" - CYAN = "\e[36m" - WHITE = "\e[37m" - - def self.add(namespace, subscriber) - subscribers[namespace.to_sym] = subscriber - end - - def self.subscribers - @subscribers ||= {} - end - - def self.dispatch(args) - namespace, name = args[0].split(".") - subscriber = subscribers[namespace.to_sym] - - if subscriber.respond_to?(name) && subscriber.logger - begin - subscriber.send(name, ActiveSupport::Notifications::Event.new(*args)) - rescue Exception => e - Rails.logger.error "Could not log #{args[0].inspect} event. #{e.class}: #{e.message}" - end - end - end - - # Flush all subscribers' logger. - def self.flush_all! - loggers = subscribers.values.map(&:logger) - loggers.uniq! - loggers.each { |l| l.flush if l.respond_to?(:flush) } - end - - # By default, we use the Rails.logger for logging. - def logger - Rails.logger - end - - protected - - %w(info debug warn error fatal unknown).each do |level| - class_eval <<-METHOD, __FILE__, __LINE__ + 1 - def #{level}(*args, &block) - logger.#{level}(*args, &block) - end - METHOD - end - - # Set color by using a string or one of the defined constants. If a third - # option is set to true, it also adds bold to the string. This is based - # on Highline implementation and it automatically appends CLEAR to the end - # of the returned String. - # - def color(text, color, bold=false) - return text unless colorize_logging - color = self.class.const_get(color.to_s.upcase) if color.is_a?(Symbol) - bold = bold ? BOLD : "" - "#{bold}#{color}#{text}#{CLEAR}" - end - end -end \ No newline at end of file diff --git a/railties/lib/rails/subscriber/test_helper.rb b/railties/lib/rails/subscriber/test_helper.rb deleted file mode 100644 index 39b4117372..0000000000 --- a/railties/lib/rails/subscriber/test_helper.rb +++ /dev/null @@ -1,98 +0,0 @@ -require 'rails/subscriber' - -module Rails - class Subscriber - # Provides some helpers to deal with testing subscribers by setting up - # notifications. Take for instance ActiveRecord subscriber tests: - # - # class SyncSubscriberTest < ActiveSupport::TestCase - # include Rails::Subscriber::TestHelper - # Rails::Subscriber.add(:active_record, ActiveRecord::Railties::Subscriber.new) - # - # def test_basic_query_logging - # Developer.all - # wait - # assert_equal 1, @logger.logged(:debug).size - # assert_match /Developer Load/, @logger.logged(:debug).last - # assert_match /SELECT \* FROM "developers"/, @logger.logged(:debug).last - # end - # - # class SyncSubscriberTest < ActiveSupport::TestCase - # include Rails::Subscriber::SyncTestHelper - # include SubscriberTest - # end - # - # class AsyncSubscriberTest < ActiveSupport::TestCase - # include Rails::Subscriber::AsyncTestHelper - # include SubscriberTest - # end - # end - # - # All you need to do is to ensure that your subscriber is added to Rails::Subscriber, - # as in the second line of the code above. The test helpers is reponsible for setting - # up the queue, subscriptions and turning colors in logs off. - # - # The messages are available in the @logger instance, which is a logger with limited - # powers (it actually do not send anything to your output), and you can collect them - # doing @logger.logged(level), where level is the level used in logging, like info, - # debug, warn and so on. - # - module TestHelper - def setup - @logger = MockLogger.new - @notifier = ActiveSupport::Notifications::Notifier.new(queue) - - Rails::Subscriber.colorize_logging = false - @notifier.subscribe { |*args| Rails::Subscriber.dispatch(args) } - - set_logger(@logger) - ActiveSupport::Notifications.notifier = @notifier - end - - def teardown - set_logger(nil) - ActiveSupport::Notifications.notifier = nil - end - - class MockLogger - attr_reader :flush_count - - def initialize - @flush_count = 0 - @logged = Hash.new { |h,k| h[k] = [] } - end - - def method_missing(level, message) - @logged[level] << message - end - - def logged(level) - @logged[level].compact.map { |l| l.to_s.strip } - end - - def flush - @flush_count += 1 - end - end - - # Wait notifications to be published. - def wait - @notifier.wait - end - - # Overwrite if you use another logger in your subscriber: - # - # def logger - # ActiveRecord::Base.logger = @logger - # end - # - def set_logger(logger) - Rails.logger = logger - end - - def queue - ActiveSupport::Notifications::Fanout.new - end - end - end -end \ No newline at end of file diff --git a/railties/test/application/initializers/notifications_test.rb b/railties/test/application/initializers/notifications_test.rb index 061bb34c19..b99cf5bb4f 100644 --- a/railties/test/application/initializers/notifications_test.rb +++ b/railties/test/application/initializers/notifications_test.rb @@ -28,7 +28,7 @@ module ApplicationTests ActiveSupport::Notifications.notifier.wait end - test "rails subscribers are added" do + test "rails log_subscribers are added" do add_to_config <<-RUBY config.colorize_logging = false RUBY diff --git a/railties/test/log_subscriber_test.rb b/railties/test/log_subscriber_test.rb new file mode 100644 index 0000000000..be176df1bb --- /dev/null +++ b/railties/test/log_subscriber_test.rb @@ -0,0 +1,119 @@ +require 'abstract_unit' +require 'rails/log_subscriber/test_helper' + +class MyLogSubscriber < Rails::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, true)}" + end + + def puke(event) + raise "puke" + end +end + +class SyncLogSubscriberTest < ActiveSupport::TestCase + include Rails::LogSubscriber::TestHelper + + def setup + super + @log_subscriber = MyLogSubscriber.new + Rails::LogSubscriber.instance_variable_set(:@log_tailer, nil) + end + + def teardown + super + Rails::LogSubscriber.log_subscribers.clear + Rails::LogSubscriber.instance_variable_set(:@log_tailer, nil) + 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 + Rails::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_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 + Rails::LogSubscriber.add :my_log_subscriber, @log_subscriber + instrument "my_log_subscriber.some_event" + wait + assert_equal %w(my_log_subscriber.some_event), @logger.logged(:info) + end + + def test_event_is_an_active_support_notifications_event + Rails::LogSubscriber.add :my_log_subscriber, @log_subscriber + instrument "my_log_subscriber.some_event" + wait + assert_kind_of ActiveSupport::Notifications::Event, @log_subscriber.event + end + + def test_does_not_send_the_event_if_it_doesnt_match_the_class + Rails::LogSubscriber.add :my_log_subscriber, @log_subscriber + instrument "my_log_subscriber.unknown_event" + wait + # If we get here, it means that NoMethodError was raised. + end + + def test_does_not_send_the_event_if_logger_is_nil + Rails.logger = nil + @log_subscriber.expects(:some_event).never + Rails::LogSubscriber.add :my_log_subscriber, @log_subscriber + instrument "my_log_subscriber.some_event" + wait + end + + def test_flushes_loggers + Rails::LogSubscriber.add :my_log_subscriber, @log_subscriber + Rails::LogSubscriber.flush_all! + assert_equal 1, @logger.flush_count + end + + def test_flushes_the_same_logger_just_once + Rails::LogSubscriber.add :my_log_subscriber, @log_subscriber + Rails::LogSubscriber.add :another, @log_subscriber + Rails::LogSubscriber.flush_all! + wait + assert_equal 1, @logger.flush_count + end + + def test_logging_does_not_die_on_failures + Rails::LogSubscriber.add :my_log_subscriber, @log_subscriber + instrument "my_log_subscriber.puke" + instrument "my_log_subscriber.some_event" + wait + + assert_equal 1, @logger.logged(:info).size + assert_equal 'my_log_subscriber.some_event', @logger.logged(:info).last + + assert_equal 1, @logger.logged(:error).size + assert_equal 'Could not log "my_log_subscriber.puke" event. RuntimeError: puke', @logger.logged(:error).last + end +end \ No newline at end of file diff --git a/railties/test/railties/railtie_test.rb b/railties/test/railties/railtie_test.rb index b723e08281..9eb4e9993a 100644 --- a/railties/test/railties/railtie_test.rb +++ b/railties/test/railties/railtie_test.rb @@ -51,12 +51,12 @@ module RailtiesTest assert_equal "bar", Bar.config.foo.bar end - test "railtie can add subscribers" do + test "railtie can add log subscribers" do begin - class Foo < Rails::Railtie ; subscriber(Rails::Subscriber.new) ; end - assert_kind_of Rails::Subscriber, Rails::Subscriber.subscribers[:foo] + class Foo < Rails::Railtie ; log_subscriber(Rails::LogSubscriber.new) ; end + assert_kind_of Rails::LogSubscriber, Rails::LogSubscriber.log_subscribers[:foo] ensure - Rails::Subscriber.subscribers.clear + Rails::LogSubscriber.log_subscribers.clear end end diff --git a/railties/test/subscriber_test.rb b/railties/test/subscriber_test.rb deleted file mode 100644 index f6c895093f..0000000000 --- a/railties/test/subscriber_test.rb +++ /dev/null @@ -1,119 +0,0 @@ -require 'abstract_unit' -require 'rails/subscriber/test_helper' - -class MySubscriber < Rails::Subscriber - 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, true)}" - end - - def puke(event) - raise "puke" - end -end - -class SyncSubscriberTest < ActiveSupport::TestCase - include Rails::Subscriber::TestHelper - - def setup - super - @subscriber = MySubscriber.new - Rails::Subscriber.instance_variable_set(:@log_tailer, nil) - end - - def teardown - super - Rails::Subscriber.subscribers.clear - Rails::Subscriber.instance_variable_set(:@log_tailer, nil) - end - - def instrument(*args, &block) - ActiveSupport::Notifications.instrument(*args, &block) - end - - def test_proxies_method_to_rails_logger - @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 - Rails::Subscriber.colorize_logging = true - @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 - @subscriber.bar(nil) - assert_equal "cool, isn't it?", @logger.logged(:info).last - end - - def test_event_is_sent_to_the_registered_class - Rails::Subscriber.add :my_subscriber, @subscriber - instrument "my_subscriber.some_event" - wait - assert_equal %w(my_subscriber.some_event), @logger.logged(:info) - end - - def test_event_is_an_active_support_notifications_event - Rails::Subscriber.add :my_subscriber, @subscriber - instrument "my_subscriber.some_event" - wait - assert_kind_of ActiveSupport::Notifications::Event, @subscriber.event - end - - def test_does_not_send_the_event_if_it_doesnt_match_the_class - Rails::Subscriber.add :my_subscriber, @subscriber - instrument "my_subscriber.unknown_event" - wait - # If we get here, it means that NoMethodError was raised. - end - - def test_does_not_send_the_event_if_logger_is_nil - Rails.logger = nil - @subscriber.expects(:some_event).never - Rails::Subscriber.add :my_subscriber, @subscriber - instrument "my_subscriber.some_event" - wait - end - - def test_flushes_loggers - Rails::Subscriber.add :my_subscriber, @subscriber - Rails::Subscriber.flush_all! - assert_equal 1, @logger.flush_count - end - - def test_flushes_the_same_logger_just_once - Rails::Subscriber.add :my_subscriber, @subscriber - Rails::Subscriber.add :another, @subscriber - Rails::Subscriber.flush_all! - wait - assert_equal 1, @logger.flush_count - end - - def test_logging_does_not_die_on_failures - Rails::Subscriber.add :my_subscriber, @subscriber - instrument "my_subscriber.puke" - instrument "my_subscriber.some_event" - wait - - assert_equal 1, @logger.logged(:info).size - assert_equal 'my_subscriber.some_event', @logger.logged(:info).last - - assert_equal 1, @logger.logged(:error).size - assert_equal 'Could not log "my_subscriber.puke" event. RuntimeError: puke', @logger.logged(:error).last - end -end \ No newline at end of file -- cgit v1.2.3