diff options
Diffstat (limited to 'railties')
| -rw-r--r-- | railties/lib/rails/commands/server.rb | 11 | ||||
| -rw-r--r-- | railties/lib/rails/configuration.rb | 12 | ||||
| -rw-r--r-- | railties/lib/rails/rack.rb | 1 | ||||
| -rw-r--r-- | railties/lib/rails/rack/logger.rb | 38 | ||||
| -rw-r--r-- | railties/lib/rails/subscriber.rb | 7 | ||||
| -rw-r--r-- | railties/lib/rails/subscriber/test_helper.rb | 26 | ||||
| -rw-r--r-- | railties/test/application/middleware_test.rb | 2 | ||||
| -rw-r--r-- | railties/test/subscriber_test.rb | 45 |
8 files changed, 61 insertions, 81 deletions
diff --git a/railties/lib/rails/commands/server.rb b/railties/lib/rails/commands/server.rb index 115499db05..b21ae2a17b 100644 --- a/railties/lib/rails/commands/server.rb +++ b/railties/lib/rails/commands/server.rb @@ -46,7 +46,6 @@ module Rails trap(:INT) { exit } puts "=> Ctrl-C to shutdown server" unless options[:daemonize] - initialize_log_tailer! unless options[:daemonize] super ensure puts 'Exiting' unless options[:daemonize] @@ -54,6 +53,7 @@ module Rails def middleware middlewares = [] + middlewares << [Rails::Rack::LogTailer, log_path] unless options[:daemonize] middlewares << [Rails::Rack::Debugger] if options[:debugger] Hash.new(middlewares) end @@ -71,14 +71,5 @@ module Rails :pid => "tmp/pids/server.pid" }) end - - protected - - # LogTailer should not be used as a middleware since the logging happens - # async in a request and the middleware calls are sync. So we send it - # to subscriber which will be responsible for calling tail! in the log tailer. - def initialize_log_tailer! - Rails::Subscriber.log_tailer = Rails::Rack::LogTailer.new(nil, log_path) - end end end diff --git a/railties/lib/rails/configuration.rb b/railties/lib/rails/configuration.rb index a9586b6e9e..c7331f79c5 100644 --- a/railties/lib/rails/configuration.rb +++ b/railties/lib/rails/configuration.rb @@ -10,15 +10,15 @@ module Rails def self.default_middleware_stack ActionDispatch::MiddlewareStack.new.tap do |middleware| - middleware.use('ActionDispatch::Static', lambda { Rails.public_path }, :if => lambda { Rails.application.config.serve_static_assets }) + middleware.use('::ActionDispatch::Static', lambda { Rails.public_path }, :if => lambda { Rails.application.config.serve_static_assets }) middleware.use('::Rack::Lock', :if => lambda { !ActionController::Base.allow_concurrency }) middleware.use('::Rack::Runtime') - middleware.use('ActionDispatch::ShowExceptions', lambda { ActionController::Base.consider_all_requests_local }) - middleware.use('ActionDispatch::Notifications') - middleware.use('ActionDispatch::Callbacks', lambda { !Rails.application.config.cache_classes }) - middleware.use('ActionDispatch::Cookies') + middleware.use('::Rails::Rack::Logger') + middleware.use('::ActionDispatch::ShowExceptions', lambda { ActionController::Base.consider_all_requests_local }) + middleware.use('::ActionDispatch::Callbacks', lambda { !Rails.application.config.cache_classes }) + middleware.use('::ActionDispatch::Cookies') middleware.use(lambda { ActionController::Base.session_store }, lambda { ActionController::Base.session_options }) - middleware.use('ActionDispatch::Flash', :if => lambda { ActionController::Base.session_store }) + middleware.use('::ActionDispatch::Flash', :if => lambda { ActionController::Base.session_store }) middleware.use(lambda { Rails::Rack::Metal.new(Rails.application.config.paths.app.metals.to_a, Rails.application.config.metals) }) middleware.use('ActionDispatch::ParamsParser') middleware.use('::Rack::MethodOverride') diff --git a/railties/lib/rails/rack.rb b/railties/lib/rails/rack.rb index 36945a6b0f..4bc0c2c88b 100644 --- a/railties/lib/rails/rack.rb +++ b/railties/lib/rails/rack.rb @@ -1,6 +1,7 @@ module Rails module Rack autoload :Debugger, "rails/rack/debugger" + autoload :Logger, "rails/rack/logger" autoload :LogTailer, "rails/rack/log_tailer" autoload :Metal, "rails/rack/metal" autoload :Static, "rails/rack/static" diff --git a/railties/lib/rails/rack/logger.rb b/railties/lib/rails/rack/logger.rb new file mode 100644 index 0000000000..91a613092f --- /dev/null +++ b/railties/lib/rails/rack/logger.rb @@ -0,0 +1,38 @@ +require 'rails/subscriber' + +module Rails + module Rack + # Log the request started and flush all loggers after it. + class Logger < Rails::Subscriber + def initialize(app) + @app = app + end + + def call(env) + @env = env + before_dispatch + result = @app.call(@env) + after_dispatch + result + end + + protected + + def request + @request ||= ActionDispatch::Request.new(@env) + end + + def before_dispatch + path = request.request_uri.inspect rescue "unknown" + + info "\n\nStarted #{request.method.to_s.upcase} #{path} " << + "for #{request.remote_ip} at #{Time.now.to_s(:db)}" + end + + def after_dispatch + Rails::Subscriber.flush_all! + end + + end + end +end diff --git a/railties/lib/rails/subscriber.rb b/railties/lib/rails/subscriber.rb index 9965786d86..8c62f562d9 100644 --- a/railties/lib/rails/subscriber.rb +++ b/railties/lib/rails/subscriber.rb @@ -33,7 +33,7 @@ module Rails # 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, :log_tailer + mattr_accessor :colorize_logging self.colorize_logging = true # Embed in a String to clear all previous ANSI sequences. @@ -69,11 +69,6 @@ module Rails Rails.logger.error "Could not log #{args[0].inspect} event. #{e.class}: #{e.message}" end end - - if args[0] == "action_dispatch.after_dispatch" && !subscribers.empty? - flush_all! - log_tailer.tail! if log_tailer - end end # Flush all subscribers' logger. diff --git a/railties/lib/rails/subscriber/test_helper.rb b/railties/lib/rails/subscriber/test_helper.rb index 1464767ed9..39b4117372 100644 --- a/railties/lib/rails/subscriber/test_helper.rb +++ b/railties/lib/rails/subscriber/test_helper.rb @@ -1,12 +1,12 @@ require 'rails/subscriber' -require 'active_support/notifications' module Rails class Subscriber # Provides some helpers to deal with testing subscribers by setting up # notifications. Take for instance ActiveRecord subscriber tests: # - # module SubscriberTest + # class SyncSubscriberTest < ActiveSupport::TestCase + # include Rails::Subscriber::TestHelper # Rails::Subscriber.add(:active_record, ActiveRecord::Railties::Subscriber.new) # # def test_basic_query_logging @@ -39,8 +39,6 @@ module Rails # module TestHelper def setup - Thread.abort_on_exception = true - @logger = MockLogger.new @notifier = ActiveSupport::Notifications::Notifier.new(queue) @@ -54,7 +52,6 @@ module Rails def teardown set_logger(nil) ActiveSupport::Notifications.notifier = nil - Thread.abort_on_exception = false end class MockLogger @@ -92,26 +89,9 @@ module Rails def set_logger(logger) Rails.logger = logger end - end - - module SyncTestHelper - include TestHelper - - def queue - ActiveSupport::Notifications::Fanout.new(true) - end - end - - module AsyncTestHelper - include TestHelper def queue - ActiveSupport::Notifications::Fanout.new(false) - end - - def wait - sleep(0.01) - super + ActiveSupport::Notifications::Fanout.new end end end diff --git a/railties/test/application/middleware_test.rb b/railties/test/application/middleware_test.rb index 1c5cc62ecd..8c4247e840 100644 --- a/railties/test/application/middleware_test.rb +++ b/railties/test/application/middleware_test.rb @@ -17,8 +17,8 @@ module ApplicationTests "ActionDispatch::Static", "Rack::Lock", "Rack::Runtime", + "Rails::Rack::Logger", "ActionDispatch::ShowExceptions", - "ActionDispatch::Notifications", "ActionDispatch::Callbacks", "ActionDispatch::Cookies", "ActionDispatch::Session::CookieStore", diff --git a/railties/test/subscriber_test.rb b/railties/test/subscriber_test.rb index 724e8a75d6..f6c895093f 100644 --- a/railties/test/subscriber_test.rb +++ b/railties/test/subscriber_test.rb @@ -24,7 +24,9 @@ class MySubscriber < Rails::Subscriber end end -module SubscriberTest +class SyncSubscriberTest < ActiveSupport::TestCase + include Rails::Subscriber::TestHelper + def setup super @subscriber = MySubscriber.new @@ -94,51 +96,24 @@ module SubscriberTest assert_equal 1, @logger.flush_count end - def test_flushes_loggers_when_action_dispatch_callback_is_received - Rails::Subscriber.add :my_subscriber, @subscriber - instrument "action_dispatch.after_dispatch" - wait - 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 - instrument "action_dispatch.after_dispatch" + Rails::Subscriber.flush_all! wait assert_equal 1, @logger.flush_count end - def test_logging_thread_does_not_die_on_failures + def test_logging_does_not_die_on_failures Rails::Subscriber.add :my_subscriber, @subscriber instrument "my_subscriber.puke" - instrument "action_dispatch.after_dispatch" - wait - assert_equal 1, @logger.flush_count - assert_equal 1, @logger.logged(:error).size - assert_equal 'Could not log "my_subscriber.puke" event. RuntimeError: puke', @logger.logged(:error).last - end - - def test_tails_logs_when_action_dispatch_callback_is_received - log_tailer = mock() - log_tailer.expects(:tail!) - Rails::Subscriber.log_tailer = log_tailer - - Rails::Subscriber.add :my_subscriber, @subscriber - instrument "action_dispatch.after_dispatch" + instrument "my_subscriber.some_event" wait - ensure - Rails::Subscriber.log_tailer = nil - end - class SyncSubscriberTest < ActiveSupport::TestCase - include Rails::Subscriber::SyncTestHelper - include SubscriberTest - end + assert_equal 1, @logger.logged(:info).size + assert_equal 'my_subscriber.some_event', @logger.logged(:info).last - class AsyncSubscriberTest < ActiveSupport::TestCase - include Rails::Subscriber::AsyncTestHelper - include SubscriberTest + 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 |