aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
Diffstat
-rw-r--r--actionpack/CHANGELOG2
-rw-r--r--actionpack/lib/action_dispatch.rb1
-rw-r--r--actionpack/lib/action_dispatch/http/request.rb10
-rw-r--r--actionpack/lib/action_dispatch/middleware/request_id.rb38
-rw-r--r--actionpack/test/dispatch/request_id_test.rb59
-rw-r--r--activesupport/CHANGELOG7
-rw-r--r--activesupport/lib/active_support.rb1
-rw-r--r--activesupport/lib/active_support/tagged_logging.rb68
-rw-r--r--activesupport/test/tagged_logging_test.rb34
-rw-r--r--railties/CHANGELOG2
-rw-r--r--railties/guides/code/getting_started/config/environments/production.rb3
-rw-r--r--railties/lib/rails/application.rb2
-rw-r--r--railties/lib/rails/application/bootstrap.rb4
-rw-r--r--railties/lib/rails/application/configuration.rb2
-rw-r--r--railties/lib/rails/rack.rb1
-rw-r--r--railties/lib/rails/rack/logger.rb4
-rw-r--r--railties/lib/rails/rack/tagged_logging.rb39
17 files changed, 272 insertions, 5 deletions
diff --git a/actionpack/CHANGELOG b/actionpack/CHANGELOG
index 29992a36b1..e7886facb9 100644
--- a/actionpack/CHANGELOG
+++ b/actionpack/CHANGELOG
@@ -1,5 +1,7 @@
*Rails 3.2.0 (unreleased)*
+* Added ActionDispatch::RequestId middleware that'll make a unique X-Request-Id header available to the response and enables the ActionDispatch::Request#uuid method. This makes it easy to trace requests from end-to-end in the stack and to identify individual requests in mixed logs like Syslog [DHH]
+
* Limit the number of options for select_year to 1000.
Pass the :max_years_allowed option to set your own limit.
diff --git a/actionpack/lib/action_dispatch.rb b/actionpack/lib/action_dispatch.rb
index 7f972fc281..c13850f378 100644
--- a/actionpack/lib/action_dispatch.rb
+++ b/actionpack/lib/action_dispatch.rb
@@ -47,6 +47,7 @@ module ActionDispatch
end
autoload_under 'middleware' do
+ autoload :RequestId
autoload :BestStandardsSupport
autoload :Callbacks
autoload :Cookies
diff --git a/actionpack/lib/action_dispatch/http/request.rb b/actionpack/lib/action_dispatch/http/request.rb
index 37d0a3e0b8..7a5237dcf3 100644
--- a/actionpack/lib/action_dispatch/http/request.rb
+++ b/actionpack/lib/action_dispatch/http/request.rb
@@ -177,6 +177,16 @@ module ActionDispatch
@remote_ip ||= (@env["action_dispatch.remote_ip"] || ip).to_s
end
+ # Returns the unique request id, which is based off either the X-Request-Id header that can
+ # be generated by a firewall, load balancer, or web server or by the RequestId middleware
+ # (which sets the action_dispatch.request_id environment variable).
+ #
+ # This unique ID is useful for tracing a request from end-to-end as part of logging or debugging.
+ # This relies on the rack variable set by the ActionDispatch::RequestId middleware.
+ def uuid
+ @uuid ||= env["action_dispatch.request_id"]
+ end
+
# Returns the lowercase name of the HTTP server software.
def server_software
(@env['SERVER_SOFTWARE'] && /^([a-zA-Z]+)/ =~ @env['SERVER_SOFTWARE']) ? $1.downcase : nil
diff --git a/actionpack/lib/action_dispatch/middleware/request_id.rb b/actionpack/lib/action_dispatch/middleware/request_id.rb
new file mode 100644
index 0000000000..968ad6c28d
--- /dev/null
+++ b/actionpack/lib/action_dispatch/middleware/request_id.rb
@@ -0,0 +1,38 @@
+require 'digest/md5'
+
+module ActionDispatch
+ # Makes a unique request id available to the action_dispatch.request_id env variable (which is then accessible through
+ # ActionDispatch::Request#uuid) and sends the same id to the client via the X-Request-Id header.
+ #
+ # The unique request id is either based off the X-Request-Id header in the request, which would typically be generated
+ # by a firewall, load balancer, or the web server, or, if this header is not available, a random uuid. If the
+ # header is accepted from the outside world, we sanitize it to a max of 255 chars and alphanumeric and dashes only.
+ #
+ # The unique request id can be used to trace a request end-to-end and would typically end up being part of log files
+ # from multiple pieces of the stack.
+ class RequestId
+ def initialize(app)
+ @app = app
+ end
+
+ def call(env)
+ env["action_dispatch.request_id"] = external_request_id(env) || internal_request_id
+
+ status, headers, body = @app.call(env)
+
+ headers["X-Request-Id"] = env["action_dispatch.request_id"]
+ [ status, headers, body ]
+ end
+
+ private
+ def external_request_id(env)
+ if env["HTTP_X_REQUEST_ID"].present?
+ env["HTTP_X_REQUEST_ID"].gsub(/[^\w\d\-]/, "").first(255)
+ end
+ end
+
+ def internal_request_id
+ SecureRandom.uuid
+ end
+ end
+end
diff --git a/actionpack/test/dispatch/request_id_test.rb b/actionpack/test/dispatch/request_id_test.rb
new file mode 100644
index 0000000000..bdadbf6644
--- /dev/null
+++ b/actionpack/test/dispatch/request_id_test.rb
@@ -0,0 +1,59 @@
+require 'abstract_unit'
+
+class RequestIdTest < ActiveSupport::TestCase
+ test "passing on the request id from the outside" do
+ assert_equal "external-uu-rid", stub_request('HTTP_X_REQUEST_ID' => 'external-uu-rid').uuid
+ end
+
+ test "ensure that only alphanumeric uurids are accepted" do
+ assert_equal "X-Hacked-HeaderStuff", stub_request('HTTP_X_REQUEST_ID' => '; X-Hacked-Header: Stuff').uuid
+ end
+
+ test "ensure that 255 char limit on the request id is being enforced" do
+ assert_equal "X" * 255, stub_request('HTTP_X_REQUEST_ID' => 'X' * 500).uuid
+ end
+
+ test "generating a request id when none is supplied" do
+ assert_match /\w+-\w+-\w+-\w+-\w+/, stub_request.uuid
+ end
+
+ private
+ def stub_request(env = {})
+ ActionDispatch::RequestId.new(->(env) { [ 200, env, [] ] }).call(env)
+ ActionDispatch::Request.new(env)
+ end
+end
+
+# FIXME: Testing end-to-end doesn't seem to work
+#
+# class RequestIdResponseTest < ActionDispatch::IntegrationTest
+# class TestController < ActionController::Base
+# def index
+# head :ok
+# end
+# end
+#
+# test "request id is passed all the way to the response" do
+# with_test_route_set do
+# get '/'
+# puts @response.headers.inspect
+# assert_equal "internal-uu-rid", @response.headers["X-Request-Id"]
+# end
+# end
+#
+#
+# private
+# def with_test_route_set
+# with_routing do |set|
+# set.draw do
+# match ':action', to: ::RequestIdResponseTest::TestController
+# end
+#
+# @app = self.class.build_app(set) do |middleware|
+# middleware.use ActionDispatch::RequestId
+# end
+#
+# yield
+# end
+# end
+# end \ No newline at end of file
diff --git a/activesupport/CHANGELOG b/activesupport/CHANGELOG
index 63f406cd9f..d3a838cff0 100644
--- a/activesupport/CHANGELOG
+++ b/activesupport/CHANGELOG
@@ -1,5 +1,12 @@
*Rails 3.2.0 (unreleased)*
+* Added ActiveSupport:TaggedLogging that can wrap any standard Logger class to provide tagging capabilities [DHH]
+
+ Logger = ActiveSupport::TaggedLogging.new(Logger.new(STDOUT))
+ Logger.tagged("BCX") { Logger.info "Stuff" } # Logs "[BCX] Stuff"
+ Logger.tagged("BCX", "Jason") { Logger.info "Stuff" } # Logs "[BCX] [Jason] Stuff"
+ Logger.tagged("BCX") { Logger.tagged("Jason") { Logger.info "Stuff" } } # Logs "[BCX] [Jason] Stuff"
+
* Added safe_constantize that constantizes a string but returns nil instead of an exception if the constant (or part of it) does not exist [Ryan Oblak]
* ActiveSupport::OrderedHash is now marked as extractable when using Array#extract_options! [Prem Sichanugrist]
diff --git a/activesupport/lib/active_support.rb b/activesupport/lib/active_support.rb
index cc9ea5cffa..ff78e718f2 100644
--- a/activesupport/lib/active_support.rb
+++ b/activesupport/lib/active_support.rb
@@ -71,6 +71,7 @@ module ActiveSupport
autoload :OrderedOptions
autoload :Rescuable
autoload :StringInquirer
+ autoload :TaggedLogging
autoload :XmlMini
end
diff --git a/activesupport/lib/active_support/tagged_logging.rb b/activesupport/lib/active_support/tagged_logging.rb
new file mode 100644
index 0000000000..0d8504bc1f
--- /dev/null
+++ b/activesupport/lib/active_support/tagged_logging.rb
@@ -0,0 +1,68 @@
+module ActiveSupport
+ # Wraps any standard Logger class to provide tagging capabilities. Examples:
+ #
+ # Logger = ActiveSupport::TaggedLogging.new(Logger.new(STDOUT))
+ # Logger.tagged("BCX") { Logger.info "Stuff" } # Logs "[BCX] Stuff"
+ # Logger.tagged("BCX", "Jason") { Logger.info "Stuff" } # Logs "[BCX] [Jason] Stuff"
+ # Logger.tagged("BCX") { Logger.tagged("Jason") { Logger.info "Stuff" } } # Logs "[BCX] [Jason] Stuff"
+ #
+ # This is used by the default Rails.logger as configured by Railties to make it easy to stamp log lines
+ # with subdomains, request ids, and anything else to aid debugging of multi-user production applications.
+ class TaggedLogging
+ def initialize(logger)
+ @logger = logger
+ @tags = []
+ end
+
+ def tagged(*tags)
+ new_tags = Array.wrap(tags).flatten
+ @tags += new_tags
+ yield
+ ensure
+ new_tags.size.times { @tags.pop }
+ end
+
+
+ def add(severity, message = nil, progname = nil, &block)
+ @logger.add(severity, "#{tags}#{message}", progname, &block)
+ end
+
+
+ def fatal(progname = nil, &block)
+ add(@logger.class::FATAL, progname, &block)
+ end
+
+ def error(progname = nil, &block)
+ add(@logger.class::ERROR, progname, &block)
+ end
+
+ def warn(progname = nil, &block)
+ add(@logger.class::WARN, progname, &block)
+ end
+
+ def info(progname = nil, &block)
+ add(@logger.class::INFO, progname, &block)
+ end
+
+ def debug(progname = nil, &block)
+ add(@logger.class::DEBUG, progname, &block)
+ end
+
+ def unknown(progname = nil, &block)
+ add(@logger.class::UNKNOWN, progname, &block)
+ end
+
+
+ def method_missing(method, *args)
+ @logger.send(method, *args)
+ end
+
+
+ private
+ def tags
+ if @tags.any?
+ @tags.collect { |tag| "[#{tag}]" }.join(" ") + " "
+ end
+ end
+ end
+end
diff --git a/activesupport/test/tagged_logging_test.rb b/activesupport/test/tagged_logging_test.rb
new file mode 100644
index 0000000000..a1504c6ce4
--- /dev/null
+++ b/activesupport/test/tagged_logging_test.rb
@@ -0,0 +1,34 @@
+require 'abstract_unit'
+require 'active_support/core_ext/logger'
+require 'active_support/tagged_logging'
+
+class TaggedLoggingTest < ActiveSupport::TestCase
+ setup do
+ @output = StringIO.new
+ @logger = ActiveSupport::TaggedLogging.new(Logger.new(@output))
+ end
+
+ test "tagged once" do
+ @logger.tagged("BCX") { @logger.info "Funky time" }
+ assert_equal "[BCX] Funky time\n", @output.string
+ end
+
+ test "tagged twice" do
+ @logger.tagged("BCX") { @logger.tagged("Jason") { @logger.info "Funky time" } }
+ assert_equal "[BCX] [Jason] Funky time\n", @output.string
+ end
+
+ test "tagged thrice at once" do
+ @logger.tagged("BCX", "Jason", "New") { @logger.info "Funky time" }
+ assert_equal "[BCX] [Jason] [New] Funky time\n", @output.string
+ end
+
+ test "mixed levels of tagging" do
+ @logger.tagged("BCX") do
+ @logger.tagged("Jason") { @logger.info "Funky time" }
+ @logger.info "Junky time!"
+ end
+
+ assert_equal "[BCX] [Jason] Funky time\n[BCX] Junky time!\n", @output.string
+ end
+end
diff --git a/railties/CHANGELOG b/railties/CHANGELOG
index 187dd2428f..181019f851 100644
--- a/railties/CHANGELOG
+++ b/railties/CHANGELOG
@@ -1,5 +1,7 @@
*Rails 3.2.0 (unreleased)*
+* Added Rails::Rack::TaggedLogging middleware by default that will apply any tags set in config.log_tags to the newly ActiveSupport::TaggedLogging Rails.logger. This makes it easy to tag log lines with debug information like subdomain and request id -- both very helpful in debugging multi-user production applications [DHH]
+
* Default options to `rails new` can be set in ~/.railsrc [Guillermo Iguaran]
* Added destroy alias to Rails engines. [Guillermo Iguaran]
diff --git a/railties/guides/code/getting_started/config/environments/production.rb b/railties/guides/code/getting_started/config/environments/production.rb
index 6ab63d30a6..4618191d6b 100644
--- a/railties/guides/code/getting_started/config/environments/production.rb
+++ b/railties/guides/code/getting_started/config/environments/production.rb
@@ -33,6 +33,9 @@ Blog::Application.configure do
# See everything in the log (default is :info)
# config.log_level = :debug
+ # Prepend all log lines with the following tags
+ # config.log_tags = [ :subdomain, :uuid ]
+
# Use a different logger for distributed setups
# config.logger = SyslogLogger.new
diff --git a/railties/lib/rails/application.rb b/railties/lib/rails/application.rb
index cbb2d23238..a097cfd1be 100644
--- a/railties/lib/rails/application.rb
+++ b/railties/lib/rails/application.rb
@@ -164,6 +164,8 @@ module Rails
middleware.use ::Rack::Lock unless config.allow_concurrency
middleware.use ::Rack::Runtime
middleware.use ::Rack::MethodOverride
+ middleware.use ::ActionDispatch::RequestId
+ middleware.use ::Rails::Rack::TaggedLogging, config.log_tags
middleware.use ::Rails::Rack::Logger # must come after Rack::MethodOverride to properly log overridden methods
middleware.use ::ActionDispatch::ShowExceptions, config.consider_all_requests_local
middleware.use ::ActionDispatch::RemoteIp, config.action_dispatch.ip_spoofing_check, config.action_dispatch.trusted_proxies
diff --git a/railties/lib/rails/application/bootstrap.rb b/railties/lib/rails/application/bootstrap.rb
index 0aff05b681..c2cb121e42 100644
--- a/railties/lib/rails/application/bootstrap.rb
+++ b/railties/lib/rails/application/bootstrap.rb
@@ -24,12 +24,12 @@ module Rails
initializer :initialize_logger, :group => :all do
Rails.logger ||= config.logger || begin
path = config.paths["log"].first
- logger = ActiveSupport::BufferedLogger.new(path)
+ logger = ActiveSupport::TaggedLogging.new(ActiveSupport::BufferedLogger.new(path))
logger.level = ActiveSupport::BufferedLogger.const_get(config.log_level.to_s.upcase)
logger.auto_flushing = false if Rails.env.production?
logger
rescue StandardError
- logger = ActiveSupport::BufferedLogger.new(STDERR)
+ logger = ActiveSupport::TaggedLogging.new(ActiveSupport::BufferedLogger.new(STDERR))
logger.level = ActiveSupport::BufferedLogger::WARN
logger.warn(
"Rails Error: Unable to access log file. Please ensure that #{path} exists and is chmod 0666. " +
diff --git a/railties/lib/rails/application/configuration.rb b/railties/lib/rails/application/configuration.rb
index 448521d2f0..8f5b28faf8 100644
--- a/railties/lib/rails/application/configuration.rb
+++ b/railties/lib/rails/application/configuration.rb
@@ -8,7 +8,7 @@ module Rails
attr_accessor :allow_concurrency, :asset_host, :asset_path, :assets,
:cache_classes, :cache_store, :consider_all_requests_local,
:dependency_loading, :filter_parameters,
- :force_ssl, :helpers_paths, :logger, :preload_frameworks,
+ :force_ssl, :helpers_paths, :logger, :log_tags, :preload_frameworks,
:reload_plugins, :secret_token, :serve_static_assets,
:ssl_options, :static_cache_control, :session_options,
:time_zone, :whiny_nils
diff --git a/railties/lib/rails/rack.rb b/railties/lib/rails/rack.rb
index d1ee96f7fd..b78293e570 100644
--- a/railties/lib/rails/rack.rb
+++ b/railties/lib/rails/rack.rb
@@ -3,5 +3,6 @@ module Rails
autoload :Debugger, "rails/rack/debugger"
autoload :Logger, "rails/rack/logger"
autoload :LogTailer, "rails/rack/log_tailer"
+ autoload :TaggedLogging, "rails/rack/tagged_logging"
end
end
diff --git a/railties/lib/rails/rack/logger.rb b/railties/lib/rails/rack/logger.rb
index 3be262de08..4d388c4d10 100644
--- a/railties/lib/rails/rack/logger.rb
+++ b/railties/lib/rails/rack/logger.rb
@@ -21,8 +21,8 @@ module Rails
request = ActionDispatch::Request.new(env)
path = request.filtered_path
- info "\n\nStarted #{request.request_method} \"#{path}\" " \
- "for #{request.ip} at #{Time.now.to_default_s}"
+ info "\n\n"
+ info "Started #{request.request_method} \"#{path}\" for #{request.ip} at #{Time.now.to_default_s}"
end
def after_dispatch(env)
diff --git a/railties/lib/rails/rack/tagged_logging.rb b/railties/lib/rails/rack/tagged_logging.rb
new file mode 100644
index 0000000000..7980319b37
--- /dev/null
+++ b/railties/lib/rails/rack/tagged_logging.rb
@@ -0,0 +1,39 @@
+module Rails
+ module Rack
+ # Enables easy tagging of any logging activity that occurs within the Rails request cycle. The tags are configured via the
+ # config.log_tags setting. The tags can either be strings, procs taking a request argument, or the symbols :uuid or :subdomain.
+ # The latter two are then automatically expanded to request.uuid and request.subdaomins.first -- the two most common tags
+ # desired in production logs.
+ class TaggedLogging
+ def initialize(app, tags = nil)
+ @app, @tags = app, tags
+ end
+
+ def call(env)
+ if @tags
+ Rails.logger.tagged(compute_tags(env)) { @app.call(env) }
+ else
+ @app.call(env)
+ end
+ end
+
+ private
+ def compute_tags(env)
+ request = ActionDispatch::Request.new(env)
+
+ @tags.collect do |tag|
+ case tag
+ when Proc
+ tag.call(request)
+ when :uuid
+ request.uuid
+ when :subdomain
+ request.subdomains.first
+ else
+ tag
+ end
+ end
+ end
+ end
+ end
+end
generated by cgit v1.2.3 (git 2.25.1) at 2024-06-26 04:21:03 +0000